From 584f9ec69fea19e1fed4a37699cb83e0d3c9bf94 Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Fri, 10 Jan 2014 16:03:54 +0100 Subject: Implement new telnet logging system --- lib/common_test/src/ct_conn_log_h.erl | 22 +- lib/common_test/src/ct_gen_conn.erl | 19 ++ lib/common_test/src/ct_netconfc.erl | 27 +- lib/common_test/src/ct_telnet.erl | 471 +++++++++++++++++++--------------- lib/common_test/src/ct_util.hrl | 8 +- lib/common_test/src/cth_conn_log.erl | 26 +- lib/common_test/src/unix_telnet.erl | 55 ++-- 7 files changed, 364 insertions(+), 264 deletions(-) (limited to 'lib/common_test/src') diff --git a/lib/common_test/src/ct_conn_log_h.erl b/lib/common_test/src/ct_conn_log_h.erl index ac08a3e0ad..550f62f4c1 100644 --- a/lib/common_test/src/ct_conn_log_h.erl +++ b/lib/common_test/src/ct_conn_log_h.erl @@ -96,6 +96,10 @@ terminate(_,#state{logs=Logs}) -> %%%----------------------------------------------------------------- %%% Writing reports +write_report(_Time,#conn_log{header=false,module=ConnMod}=Info,Data,State) -> + {LogType,Fd} = get_log(Info,State), + io:format(Fd,"~n~ts",[format_data(ConnMod,LogType,Data)]); + write_report(Time,#conn_log{module=ConnMod}=Info,Data,State) -> {LogType,Fd} = get_log(Info,State), io:format(Fd,"~n~ts~ts~ts",[format_head(ConnMod,LogType,Time), @@ -147,7 +151,12 @@ format_head(ConnMod,_,Time,Text) -> io_lib:format("~n~ts",[Head]). format_title(raw,#conn_log{client=Client}=Info) -> - io_lib:format("Client ~w ~s ~ts",[Client,actionstr(Info),serverstr(Info)]); + case actionstr(Info) of + {no_server,Action} -> + io_lib:format("Client ~w ~s",[Client,Action]); + Action -> + io_lib:format("Client ~w ~s ~ts",[Client,Action,serverstr(Info)]) + end; format_title(_,Info) -> Title = pad_char_end(?WIDTH,pretty_title(Info),$=), io_lib:format("~n~ts", [Title]). @@ -195,13 +204,20 @@ pretty_title(#conn_log{client=Client}=Info) -> [Client,actionstr(Info),serverstr(Info)]). actionstr(#conn_log{action=send}) -> "----->"; +actionstr(#conn_log{action=cmd}) -> "----->"; actionstr(#conn_log{action=recv}) -> "<-----"; -actionstr(#conn_log{action=open}) -> "opened session to"; -actionstr(#conn_log{action=close}) -> "closed session to"; +actionstr(#conn_log{action=open}) -> "open session to"; +actionstr(#conn_log{action=close}) -> "close session to"; +actionstr(#conn_log{action=info}) -> {no_server,"info"}; +actionstr(#conn_log{action=error}) -> {no_server,"error"}; actionstr(_) -> "<---->". +serverstr(#conn_log{name=undefined,address={undefined,_}}) -> + io_lib:format("server",[]); serverstr(#conn_log{name=undefined,address=Address}) -> io_lib:format("~p",[Address]); +serverstr(#conn_log{name=Alias,address={undefined,_}}) -> + io_lib:format("~w()",[Alias]); serverstr(#conn_log{name=Alias,address=Address}) -> io_lib:format("~w(~p)",[Alias,Address]). diff --git a/lib/common_test/src/ct_gen_conn.erl b/lib/common_test/src/ct_gen_conn.erl index a5b736136f..078d6b1a44 100644 --- a/lib/common_test/src/ct_gen_conn.erl +++ b/lib/common_test/src/ct_gen_conn.erl @@ -29,6 +29,13 @@ -export([start/4, stop/1, get_conn_pid/1]). -export([call/2, call/3, return/2, do_within_time/2]). +%%---------------------------------------------------------------------- +%% Exported types +%%---------------------------------------------------------------------- +-export_type([server_id/0, + target_name/0, + key_or_name/0]). + -ifdef(debug). -define(dbg,true). -else. @@ -47,6 +54,18 @@ cb_state, ct_util_server}). +%%------------------------------------------------------------------ +%% Type declarations +%%------------------------------------------------------------------ +-type server_id() :: atom(). +%% A `ServerId' which exists in a configuration file. +-type target_name() :: atom(). +%% A name which is associated to a `server_id()' via a +%% `require' statement or a call to {@link ct:require/2} in the +%% test suite. +-type key_or_name() :: server_id() | target_name(). + + %%%----------------------------------------------------------------- %%% @spec start(Address,InitData,CallbackMod,Opts) -> %%% {ok,Handle} | {error,Reason} diff --git a/lib/common_test/src/ct_netconfc.erl b/lib/common_test/src/ct_netconfc.erl index 64fe8b4bb0..35920ec1dc 100644 --- a/lib/common_test/src/ct_netconfc.erl +++ b/lib/common_test/src/ct_netconfc.erl @@ -212,11 +212,7 @@ %%---------------------------------------------------------------------- %% Exported types %%---------------------------------------------------------------------- --export_type([hook_options/0, - conn_mod/0, - log_type/0, - key_or_name/0, - notification/0]). +-export_type([notification/0]). %%---------------------------------------------------------------------- %% Internal exports @@ -292,19 +288,11 @@ %%---------------------------------------------------------------------- %% Type declarations %%---------------------------------------------------------------------- --type client() :: handle() | server_id() | target_name(). +-type client() :: handle() | ct_gen_conn:server_id() | ct_gen_conn:target_name(). -type handle() :: term(). %% An opaque reference for a connection (netconf session). See {@link %% ct} for more information. --type server_id() :: atom(). -%% A `ServerId' which exists in a configuration file. --type target_name() :: atom(). -%% A name which is associated to a `server_id()' via a -%% `require' statement or a call to {@link ct:require/2} in the -%% test suite. --type key_or_name() :: server_id() | target_name(). - -type options() :: [option()]. %% Options used for setting up ssh connection to a netconf server. @@ -326,14 +314,7 @@ %% See XML Schema for Event Notifications found in RFC5277 for further %% detail about the data format for the string values. --type hook_options() :: [hook_option()]. -%% Options that can be given to `cth_conn_log' in the `ct_hook' statement. --type hook_option() :: {log_type,log_type()} | - {hosts,[key_or_name()]}. --type log_type() :: raw | pretty | html | silent. %-type error_handler() :: module(). --type conn_mod() :: ct_netconfc. - -type error_reason() :: term(). -type simple_xml() :: {xml_tag(), xml_attributes(), xml_content()} | @@ -384,7 +365,7 @@ open(Options) -> %%---------------------------------------------------------------------- -spec open(KeyOrName, ExtraOptions) -> Result when - KeyOrName :: key_or_name(), + KeyOrName :: ct_gen_conn:key_or_name(), ExtraOptions :: options(), Result :: {ok,handle()} | {error,error_reason()}. %% @doc Open a named netconf session and exchange `hello' messages. @@ -461,7 +442,7 @@ only_open(Options) -> %%---------------------------------------------------------------------- -spec only_open(KeyOrName,ExtraOptions) -> Result when - KeyOrName :: key_or_name(), + KeyOrName :: ct_gen_conn:key_or_name(), ExtraOptions :: options(), Result :: {ok,handle()} | {error,error_reason()}. %% @doc Open a name netconf session, but don't send `hello'. diff --git a/lib/common_test/src/ct_telnet.erl b/lib/common_test/src/ct_telnet.erl index 4092d33bc0..5fc89be0c5 100644 --- a/lib/common_test/src/ct_telnet.erl +++ b/lib/common_test/src/ct_telnet.erl @@ -61,8 +61,6 @@ -module(ct_telnet). --compile(export_all). - -export([open/1, open/2, open/3, open/4, close/1]). -export([cmd/2, cmd/3, cmdf/3, cmdf/4, get_data/1, send/2, sendf/3, expect/2, expect/3]). @@ -71,10 +69,9 @@ -export([init/3,handle_msg/2,reconnect/2,terminate/2]). %% Tool internals --export([silent_teln_expect/5, teln_receive_until_prompt/3, - start_log/1, log/3, cont_log/2, end_log/0, - try_start_log/1, try_log/3, try_cont_log/2, try_end_log/0]). - +-export([silent_teln_expect/6, teln_receive_until_prompt/3, + format_data/2]). +-export([start_gen_log/1, end_gen_log/0, log/3, log/4]). -define(RECONNS,3). -define(RECONN_TIMEOUT,5000). @@ -83,12 +80,14 @@ -include("ct_util.hrl"). --record(state,{teln_pid, +-record(state,{host, + port, + teln_pid, prx, - type, buffer=[], prompt=false, name, + type, target_mod, keep_alive, extra, @@ -160,8 +159,7 @@ open(KeyOrName,ConnType,TargetMod) -> open(KeyOrName,ConnType,TargetMod,Extra) -> case ct:get_config({KeyOrName,ConnType}) of undefined -> - log(heading(open,{KeyOrName,ConnType}),"Failed: ~p", - [{not_available,KeyOrName}]), + log(undefined,open,"Failed: ~p",[{not_available,KeyOrName}]), {error,{not_available,KeyOrName,ConnType}}; Addr -> Addr1 = @@ -183,8 +181,8 @@ open(KeyOrName,ConnType,TargetMod,Extra) -> end; Bool -> Bool end, - log(heading(open,{KeyOrName,ConnType}), - "Opening connection to: ~p",[Addr1]), + log(undefined,open,"Opening connection ~p to ~p", + [KeyOrName,Addr1]), ct_gen_conn:start(KeyOrName,full_addr(Addr1,ConnType), {TargetMod,KeepAlive,Extra},?MODULE) end. @@ -202,7 +200,7 @@ open(KeyOrName,ConnType,TargetMod,Extra) -> close(Connection) -> case get_handle(Connection) of {ok,Pid} -> - log("ct_telnet:close","Handle: ~w",[Pid]), + log(undefined,close,"Closing connection for handle: ~w",[Pid]), case ct_gen_conn:stop(Pid) of {error,{process_down,Pid,noproc}} -> {error,already_closed}; @@ -408,9 +406,20 @@ init(Name,{Ip,Port,Type},{TargetMod,KeepAlive,Extra}) -> Settings -> set_telnet_defaults(Settings,#state{}) end, - case catch TargetMod:connect(Ip,Port,S0#state.conn_to,KeepAlive,Extra) of + case catch TargetMod:connect(Name,Ip,Port,S0#state.conn_to, + KeepAlive,Extra) of {ok,TelnPid} -> - log(heading(init,{Name,Type}), + put({ct_telnet_pid2name,TelnPid},Name), + S1 = S0#state{host=Ip, + port=Port, + teln_pid=TelnPid, + name=Name, + type=type(Type), + target_mod=TargetMod, + keep_alive=KeepAlive, + extra=Extra, + prx=TargetMod:get_prompt_regexp()}, + log(S1,open, "Opened telnet connection\n" "IP: ~p\n" "Port: ~p\n" @@ -419,15 +428,9 @@ init(Name,{Ip,Port,Type},{TargetMod,KeepAlive,Extra}) -> "Reconnection interval: ~p\n" "Connection timeout: ~p\n" "Keep alive: ~w", - [Ip,Port,S0#state.com_to,S0#state.reconns, - S0#state.reconn_int,S0#state.conn_to,KeepAlive]), - {ok,TelnPid,S0#state{teln_pid=TelnPid, - type=type(Type), - name={Name,Type}, - target_mod=TargetMod, - keep_alive=KeepAlive, - extra=Extra, - prx=TargetMod:get_prompt_regexp()}}; + [Ip,Port,S1#state.com_to,S1#state.reconns, + S1#state.reconn_int,S1#state.conn_to,KeepAlive]), + {ok,TelnPid,S1}; {'EXIT',Reason} -> {error,Reason}; Error -> @@ -448,27 +451,31 @@ set_telnet_defaults([{reconnection_interval,RInt}|Ss],S) -> set_telnet_defaults([{keep_alive,_}|Ss],S) -> set_telnet_defaults(Ss,S); set_telnet_defaults([Unknown|Ss],S) -> - log(heading(set_telnet_defaults,{telnet_settings,Unknown}), - "Bad element in telnet_settings: ~p",[Unknown]), + force_log(S,error, + "Bad element in telnet_settings: ~p",[Unknown]), set_telnet_defaults(Ss,S); set_telnet_defaults([],S) -> S. %% @hidden handle_msg({cmd,Cmd,Timeout},State) -> - try_start_log(heading(cmd,State#state.name)), - try_cont_log("Cmd: ~p", [Cmd]), - debug_cont_log("Throwing Buffer:",[]), + start_gen_log(heading(cmd,State#state.name)), + log(State,cmd,"Cmd: ~p",[Cmd]), + + debug_cont_gen_log("Throwing Buffer:",[]), debug_log_lines(State#state.buffer), + case {State#state.type,State#state.prompt} of {ts,_} -> - silent_teln_expect(State#state.teln_pid, + silent_teln_expect(State#state.name, + State#state.teln_pid, State#state.buffer, prompt, State#state.prx, [{timeout,2000}]); {ip,false} -> - silent_teln_expect(State#state.teln_pid, + silent_teln_expect(State#state.name, + State#state.teln_pid, State#state.buffer, prompt, State#state.prx, @@ -482,29 +489,36 @@ handle_msg({cmd,Cmd,Timeout},State) -> {Return,NewBuffer,Prompt} = case teln_cmd(State#state.teln_pid, Cmd, State#state.prx, TO) of {ok,Data,_PromptType,Rest} -> - try_cont_log("Return: ~p", [{ok,Data}]), + log(State,recv,"Return: ~p",[{ok,Data}]), {{ok,Data},Rest,true}; Error -> - Retry = {retry,{Error,State#state.name,State#state.teln_pid, + Retry = {retry,{Error, + {State#state.name, + State#state.type}, + State#state.teln_pid, {cmd,Cmd,TO}}}, - try_cont_log("Return: ~p", [Error]), + log(State,recv,"Return: ~p",[Error]), {Retry,[],false} end, - try_end_log(), + end_gen_log(), {Return,State#state{buffer=NewBuffer,prompt=Prompt}}; handle_msg({send,Cmd},State) -> - try_log(heading(send,State#state.name),"Cmd: ~p",[Cmd]), - debug_cont_log("Throwing Buffer:",[]), + log(State,send,"Cmd: ~p",[Cmd]), + + debug_cont_gen_log("Throwing Buffer:",[]), debug_log_lines(State#state.buffer), + case {State#state.type,State#state.prompt} of {ts,_} -> - silent_teln_expect(State#state.teln_pid, + silent_teln_expect(State#state.name, + State#state.teln_pid, State#state.buffer, prompt, State#state.prx, [{timeout,2000}]); {ip,false} -> - silent_teln_expect(State#state.teln_pid, + silent_teln_expect(State#state.name, + State#state.teln_pid, State#state.buffer, prompt, State#state.prx, @@ -515,19 +529,21 @@ handle_msg({send,Cmd},State) -> ct_telnet_client:send_data(State#state.teln_pid,Cmd), {ok,State#state{buffer=[],prompt=false}}; handle_msg(get_data,State) -> - try_start_log(heading(get_data,State#state.name)), + start_gen_log(heading(get_data,State#state.name)), + log(State,cmd,"Reading data...",[]), {ok,Data,Buffer} = teln_get_all_data(State#state.teln_pid, State#state.prx, State#state.buffer, [],[]), - try_cont_log("Return: ~p",[{ok,Data}]), - try_end_log(), + log(State,recv,"Return: ~p",[{ok,Data}]), + end_gen_log(), {{ok,Data},State#state{buffer=Buffer}}; handle_msg({expect,Pattern,Opts},State) -> - try_start_log(heading(expect,State#state.name)), - try_cont_log("Expect: ~p\nOpts=~p\n",[Pattern,Opts]), + start_gen_log(heading(expect,State#state.name)), + log(State,expect,"Expect: ~p\nOpts = ~p\n",[Pattern,Opts]), {Return,NewBuffer,Prompt} = - case teln_expect(State#state.teln_pid, + case teln_expect(State#state.name, + State#state.teln_pid, State#state.buffer, Pattern, State#state.prx, @@ -536,22 +552,23 @@ handle_msg({expect,Pattern,Opts},State) -> P = check_if_prompt_was_reached(Data,[]), {{ok,Data},Rest,P}; {ok,Data,HaltReason,Rest} -> - force_cont_log("HaltReason: ~p", - [HaltReason]), + force_log(State,expect,"HaltReason: ~p",[HaltReason]), P = check_if_prompt_was_reached(Data,HaltReason), {{ok,Data,HaltReason},Rest,P}; {error,Reason,Rest} -> - force_cont_log("Expect failed\n~p",[{error,Reason}]), + force_log(State,expect,"Expect failed\n~p",[{error,Reason}]), P = check_if_prompt_was_reached([],Reason), {{error,Reason},Rest,P}; {error,Reason} -> - force_cont_log("Expect failed\n~p",[{error,Reason}]), + force_log(State,expect,"Expect failed\n~p",[{error,Reason}]), P = check_if_prompt_was_reached([],Reason), {{error,Reason},[],P} end, - try_end_log(), + end_gen_log(), Return1 = case Return of - {error,_} -> {retry,{Return,State#state.name, + {error,_} -> {retry,{Return, + {State#state.name, + State#state.type}, State#state.teln_pid, {expect,Pattern,Opts}}}; _ -> Return @@ -562,18 +579,20 @@ handle_msg({expect,Pattern,Opts},State) -> %% @hidden reconnect({Ip,Port,_Type},State) -> reconnect(Ip,Port,State#state.reconns,State). -reconnect(Ip,Port,N,State=#state{target_mod=TargetMod, +reconnect(Ip,Port,N,State=#state{name=Name, + target_mod=TargetMod, keep_alive=KeepAlive, extra=Extra, conn_to=ConnTo, reconn_int=ReconnInt}) -> - case TargetMod:connect(Ip,Port,ConnTo,KeepAlive,Extra) of - {ok, NewPid} -> + case TargetMod:connect(Name,Ip,Port,ConnTo,KeepAlive,Extra) of + {ok,NewPid} -> + put({ct_telnet_pid2name,NewPid},Name), {ok, NewPid, State#state{teln_pid=NewPid}}; Error when N==0 -> Error; _Error -> - log("Reconnect failed!","Retries left: ~w",[N]), + log(State,reconnect,"Reconnect failed!","Retries left: ~w",[N]), timer:sleep(ReconnInt), reconnect(Ip,Port,N-1,State) end. @@ -581,9 +600,7 @@ reconnect(Ip,Port,N,State=#state{target_mod=TargetMod, %% @hidden terminate(TelnPid,State) -> - log(heading(terminate,State#state.name), - "Closing telnet connection.\nId: ~w", - [TelnPid]), + log(State,close,"Closing telnet connection.\nId: ~w",[TelnPid]), ct_telnet_client:close(TelnPid). @@ -637,79 +654,109 @@ check_if_prompt_was_reached(Data,_) when is_list(Data) -> check_if_prompt_was_reached(_,_) -> false. -%tc(Fun) -> -% Before = erlang:now(), -% Val = Fun(), -% After = erlang:now(), -% {now_diff(After, Before), Val}. -%now_diff({A2, B2, C2}, {A1, B1, C1}) -> -% ((A2-A1)*1000000 + B2-B1)*1000000 + C2-C1. - -heading(Function,Name) -> - io_lib:format("~w:~w ~p",[?MODULE,Function,Name]). - -%%% @hidden -%% Functions for regular (unconditional) logging, to be -%% used during connect, reconnect, disconnect etc. -log(Heading,Str,Args) -> - ct_gen_conn:log(Heading,Str,Args). -%%% @hidden -start_log(Heading) -> - ct_gen_conn:start_log(Heading). -cont_log(Str,Args) -> - ct_gen_conn:cont_log(Str,Args). -end_log() -> - ct_gen_conn:end_log(). - -%%% @hidden -%% Functions for conditional logging, to be used by -%% cmd, send, receive, expect etc (this output may be -%% silenced by user). -try_start_log(Heading) -> - do_try_log(start_log,[Heading]). -%%% @hidden -try_end_log() -> - do_try_log(end_log,[]). - -%%% @hidden -try_log(Heading,Str,Args) -> - do_try_log(log,[Heading,Str,Args]). - %%% @hidden -try_cont_log(Str,Args) -> - do_try_log(cont_log,[Str,Args]). - -%%% @hidden -do_try_log(Func,Args) -> - %% check if output is suppressed - case ct_util:is_silenced(telnet) of - true -> +%% Functions for logging ct_telnet reports and telnet data + +heading(Action,undefined) -> + io_lib:format("~w ~w",[?MODULE,Action]); +heading(Action,Name) -> + io_lib:format("~w ~w for ~p",[?MODULE,Action,Name]). + +force_log(State,Action,String,Args) -> + log(State,Action,String,Args,true). + +log(State,Action,String,Args) when is_record(State, state) -> + log(State,Action,String,Args,false); +log(Name,Action,String,Args) when is_atom(Name) -> + log(#state{name=Name},Action,String,Args,false); +log(TelnPid,Action,String,Args) when is_pid(TelnPid) -> + log(#state{teln_pid=TelnPid},Action,String,Args,false). + +log(undefined,String,Args) -> + log(#state{},undefined,String,Args,false); +log(Name,String,Args) when is_atom(Name) -> + log(#state{name=Name},undefined,String,Args,false); +log(TelnPid,String,Args) when is_pid(TelnPid) -> + log(#state{teln_pid=TelnPid},undefined,String,Args). + +log(#state{name=Name,teln_pid=TelnPid,host=Host,port=Port}, + Action,String,Args,ForcePrint) -> + Name1 = if Name == undefined -> get({ct_telnet_pid2name,TelnPid}); + true -> Name + end, + Silent = get(silent), + case ct_util:get_testdata({cth_conn_log,?MODULE}) of + Result when Result /= undefined, Result /= silent, Silent /= true -> + {PrintHeader,PreBR} = if Action==undefined -> + {false,""}; + true -> + {true,"\n"} + end, + error_logger:info_report(#conn_log{header=PrintHeader, + client=self(), + conn_pid=TelnPid, + address={Host,Port}, + name=Name1, + action=Action, + module=?MODULE}, + {PreBR++String,Args}); + Result when Result /= undefined -> ok; - false -> - apply(ct_gen_conn,Func,Args) + _ when Action == open; Action == close; Action == reconnect; + Action == info; Action == error -> + ct_gen_conn:log(heading(Action,Name1),String,Args); + _ when ForcePrint == false -> + case ct_util:is_silenced(telnet) of + true -> + ok; + false -> + ct_gen_conn:cont_log(String,Args) + end; + _ when ForcePrint == true -> + case ct_util:is_silenced(telnet) of + true -> + %% call log/3 now instead of cont_log/2 since + %% start_gen_log/1 will not have been previously called + ct_gen_conn:log(heading(Action,Name1),String,Args); + false -> + ct_gen_conn:cont_log(String,Args) + end end. -%%% @hidden -%% Functions that will force printout even if ct_telnet -%% output has been silenced, to be used for error printouts. -force_cont_log(Str,Args) -> - case ct_util:is_silenced(telnet) of - true -> - %% call log/3 now instead of cont_log/2 since - %% start_log/1 will not have been previously called - log("ct_telnet info",Str,Args); - false -> - cont_log(Str,Args) +start_gen_log(Heading) -> + case ct_util:get_testdata({cth_conn_log,?MODULE}) of + undefined -> + %% check if output is suppressed + case ct_util:is_silenced(telnet) of + true -> ok; + false -> ct_gen_conn:start_log(Heading) + end; + _ -> + ok + end. + +end_gen_log() -> + case ct_util:get_testdata({cth_conn_log,?MODULE}) of + undefined -> + %% check if output is suppressed + case ct_util:is_silenced(telnet) of + true -> ok; + false -> ct_gen_conn:end_log() + end; + _ -> + ok end. %%% @hidden %% Debug printouts. -debug_cont_log(Str,Args) -> +debug_cont_gen_log(Str,Args) -> Old = put(silent,true), - cont_log(Str,Args), + ct_gen_conn:cont_log(Str,Args), put(silent,Old). - +%% Log callback - called from the error handler process +format_data(_How,{String,Args}) -> + io_lib:format(String,Args). %%%================================================================= %%% Abstraction layer on top of ct_telnet_client.erl @@ -717,7 +764,6 @@ teln_cmd(Pid,Cmd,Prx,Timeout) -> ct_telnet_client:send_data(Pid,Cmd), teln_receive_until_prompt(Pid,Prx,Timeout). - teln_get_all_data(Pid,Prx,Data,Acc,LastLine) -> case check_for_prompt(Prx,lists:reverse(LastLine) ++ Data) of {prompt,Lines,_PromptType,Rest} -> @@ -746,11 +792,9 @@ teln_get_all_data(Pid,Prx,Data,Acc,LastLine) -> %% @doc Externally the silent_teln_expect function shall only be used %% by the TargetModule, i.e. the target specific module which %% implements connect/2 and get_prompt_regexp/0. -silent_teln_expect(Pid,Data,Pattern,Prx,Opts) -> +silent_teln_expect(Name,Pid,Data,Pattern,Prx,Opts) -> Old = put(silent,true), - try_cont_log("silent_teln_expect/5, Pattern = ~p",[Pattern]), - Result = teln_expect(Pid,Data,Pattern,Prx,Opts), - try_cont_log("silent_teln_expect -> ~p\n",[Result]), + Result = teln_expect(Name,Pid,Data,Pattern,Prx,Opts), put(silent,Old), Result. @@ -766,7 +810,7 @@ silent_teln_expect(Pid,Data,Pattern,Prx,Opts) -> %% condition is fullfilled. %% 3b) Repeat (sequence): 2) is repeated either N times or until a %% halt condition is fullfilled. -teln_expect(Pid,Data,Pattern0,Prx,Opts) -> +teln_expect(Name,Pid,Data,Pattern0,Prx,Opts) -> HaltPatterns = case get_ignore_prompt(Opts) of true -> @@ -790,7 +834,7 @@ teln_expect(Pid,Data,Pattern0,Prx,Opts) -> case get_repeat(Opts) of false -> - case teln_expect1(Data,Pattern,[],EO) of + case teln_expect1(Name,Pid,Data,Pattern,[],EO) of {ok,Matched,Rest} -> {ok,Matched,Rest}; {halt,Why,Rest} -> @@ -800,7 +844,7 @@ teln_expect(Pid,Data,Pattern0,Prx,Opts) -> end; N -> EO1 = EO#eo{repeat=N}, - repeat_expect(Data,Pattern,[],EO1) + repeat_expect(Name,Pid,Data,Pattern,[],EO1) end. convert_pattern(Pattern,Seq) @@ -855,23 +899,27 @@ get_prompt_check(Opts) -> %% Repeat either single or sequence. All match results are accumulated %% and returned when a halt condition is fulllfilled. -repeat_expect(Rest,_Pattern,Acc,#eo{repeat=0}) -> +repeat_expect(_Name,_Pid,Rest,_Pattern,Acc,#eo{repeat=0}) -> {ok,lists:reverse(Acc),done,Rest}; -repeat_expect(Data,Pattern,Acc,EO) -> - case teln_expect1(Data,Pattern,[],EO) of +repeat_expect(Name,Pid,Data,Pattern,Acc,EO) -> + case teln_expect1(Name,Pid,Data,Pattern,[],EO) of {ok,Matched,Rest} -> EO1 = EO#eo{repeat=EO#eo.repeat-1}, - repeat_expect(Rest,Pattern,[Matched|Acc],EO1); + repeat_expect(Name,Pid,Rest,Pattern,[Matched|Acc],EO1); {halt,Why,Rest} -> {ok,lists:reverse(Acc),Why,Rest}; {error,Reason} -> {error,Reason} end. -teln_expect1(Data,Pattern,Acc,EO) -> +teln_expect1(Name,Pid,Data,Pattern,Acc,EO) -> ExpectFun = case EO#eo.seq of - true -> fun() -> seq_expect(Data,Pattern,Acc,EO) end; - false -> fun() -> one_expect(Data,Pattern,EO) end + true -> fun() -> + seq_expect(Name,Pid,Data,Pattern,Acc,EO) + end; + false -> fun() -> + one_expect(Name,Pid,Data,Pattern,EO) + end end, case ExpectFun() of {match,Match,Rest} -> @@ -890,10 +938,10 @@ teln_expect1(Data,Pattern,Acc,EO) -> case NotFinished of {nomatch,Rest} -> %% One expect - teln_expect1(Rest++Data1,Pattern,[],EO); + teln_expect1(Name,Pid,Rest++Data1,Pattern,[],EO); {continue,Patterns1,Acc1,Rest} -> %% Sequence - teln_expect1(Rest++Data1,Patterns1,Acc1,EO) + teln_expect1(Name,Pid,Rest++Data1,Patterns1,Acc1,EO) end end end. @@ -913,47 +961,45 @@ get_data1(Pid) -> %% lines and each line is matched against each pattern. %% one_expect: split data chunk at prompts -one_expect(Data,Pattern,EO) when EO#eo.prompt_check==false -> +one_expect(Name,Pid,Data,Pattern,EO) when EO#eo.prompt_check==false -> % io:format("Raw Data ~p Pattern ~p EO ~p ",[Data,Pattern,EO]), - one_expect1(Data,Pattern,[],EO#eo{found_prompt=false}); -one_expect(Data,Pattern,EO) -> + one_expect1(Name,Pid,Data,Pattern,[],EO#eo{found_prompt=false}); +one_expect(Name,Pid,Data,Pattern,EO) -> case match_prompt(Data,EO#eo.prx) of {prompt,UptoPrompt,PromptType,Rest} -> case Pattern of [Prompt] when Prompt==prompt; Prompt=={prompt,PromptType} -> %% Only searching for prompt - log_lines(UptoPrompt), - try_cont_log("PROMPT: ~ts", [PromptType]), + log_lines(Name,Pid,UptoPrompt), + log(name_or_pid(Name,Pid),"PROMPT: ~ts",[PromptType]), {match,{prompt,PromptType},Rest}; [{prompt,_OtherPromptType}] -> %% Only searching for one specific prompt, not thisone - log_lines(UptoPrompt), + log_lines(Name,Pid,UptoPrompt), {nomatch,Rest}; _ -> - one_expect1(UptoPrompt,Pattern,Rest, + one_expect1(Name,Pid,UptoPrompt,Pattern,Rest, EO#eo{found_prompt=PromptType}) end; noprompt -> case Pattern of [Prompt] when Prompt==prompt; element(1,Prompt)==prompt -> %% Only searching for prompt - LastLine = log_lines_not_last(Data), + LastLine = log_lines_not_last(Name,Pid,Data), {nomatch,LastLine}; _ -> - one_expect1(Data,Pattern,[],EO#eo{found_prompt=false}) + one_expect1(Name,Pid,Data,Pattern,[], + EO#eo{found_prompt=false}) end end. -remove_zero(List) -> - [Ch || Ch <- List, Ch=/=0, Ch=/=13]. - %% one_expect1: split data chunk at lines -one_expect1(Data,Pattern,Rest,EO) -> - case match_lines(Data,Pattern,EO) of +one_expect1(Name,Pid,Data,Pattern,Rest,EO) -> + case match_lines(Name,Pid,Data,Pattern,EO) of {match,Match,MatchRest} -> {match,Match,MatchRest++Rest}; {nomatch,prompt} -> - one_expect(Rest,Pattern,EO); + one_expect(Name,Pid,Rest,Pattern,EO); {nomatch,NoMatchRest} -> {nomatch,NoMatchRest++Rest}; {halt,Why,HaltRest} -> @@ -970,77 +1016,77 @@ one_expect1(Data,Pattern,Rest,EO) -> %% searching for the next pattern in the list. %% seq_expect: Split data chunk at prompts -seq_expect(Data,[],Acc,_EO) -> +seq_expect(_Name,_Pid,Data,[],Acc,_EO) -> {match,lists:reverse(Acc),Data}; -seq_expect([],Patterns,Acc,_EO) -> +seq_expect(_Name,_Pid,[],Patterns,Acc,_EO) -> {continue,Patterns,lists:reverse(Acc),[]}; -seq_expect(Data,Patterns,Acc,EO) when EO#eo.prompt_check==false -> - seq_expect1(Data,Patterns,Acc,[],EO#eo{found_prompt=false}); -seq_expect(Data,Patterns,Acc,EO) -> +seq_expect(Name,Pid,Data,Patterns,Acc,EO) when EO#eo.prompt_check==false -> + seq_expect1(Name,Pid,Data,Patterns,Acc,[],EO#eo{found_prompt=false}); +seq_expect(Name,Pid,Data,Patterns,Acc,EO) -> case match_prompt(Data,EO#eo.prx) of {prompt,UptoPrompt,PromptType,Rest} -> - seq_expect1(UptoPrompt,Patterns,Acc,Rest, + seq_expect1(Name,Pid,UptoPrompt,Patterns,Acc,Rest, EO#eo{found_prompt=PromptType}); noprompt -> - seq_expect1(Data,Patterns,Acc,[],EO#eo{found_prompt=false}) + seq_expect1(Name,Pid,Data,Patterns,Acc,[],EO#eo{found_prompt=false}) end. %% seq_expect1: For one prompt-chunk, match each pattern - line by %% line if it is other than the prompt we are seaching for. -seq_expect1(Data,[prompt|Patterns],Acc,Rest,EO) -> +seq_expect1(Name,Pid,Data,[prompt|Patterns],Acc,Rest,EO) -> case EO#eo.found_prompt of false -> - LastLine = log_lines_not_last(Data), + LastLine = log_lines_not_last(Name,Pid,Data), %% Rest==[] because no prompt is found {continue,[prompt|Patterns],Acc,LastLine}; PromptType -> - log_lines(Data), - try_cont_log("PROMPT: ~ts", [PromptType]), - seq_expect(Rest,Patterns,[{prompt,PromptType}|Acc],EO) + log_lines(Name,Pid,Data), + log(name_or_pid(Name,Pid),"PROMPT: ~ts",[PromptType]), + seq_expect(Name,Pid,Rest,Patterns,[{prompt,PromptType}|Acc],EO) end; -seq_expect1(Data,[{prompt,PromptType}|Patterns],Acc,Rest,EO) -> +seq_expect1(Name,Pid,Data,[{prompt,PromptType}|Patterns],Acc,Rest,EO) -> case EO#eo.found_prompt of false -> - LastLine = log_lines_not_last(Data), + LastLine = log_lines_not_last(Name,Pid,Data), %% Rest==[] because no prompt is found {continue,[{prompt,PromptType}|Patterns],Acc,LastLine}; PromptType -> - log_lines(Data), - try_cont_log("PROMPT: ~ts", [PromptType]), - seq_expect(Rest,Patterns,[{prompt,PromptType}|Acc],EO); + log_lines(Name,Pid,Data), + log(name_or_pid(Name,Pid),"PROMPT: ~ts", [PromptType]), + seq_expect(Name,Pid,Rest,Patterns,[{prompt,PromptType}|Acc],EO); _OtherPromptType -> - log_lines(Data), - seq_expect(Rest,[{prompt,PromptType}|Patterns],Acc,EO) + log_lines(Name,Pid,Data), + seq_expect(Name,Pid,Rest,[{prompt,PromptType}|Patterns],Acc,EO) end; -seq_expect1(Data,[Pattern|Patterns],Acc,Rest,EO) -> - case match_lines(Data,[Pattern],EO) of +seq_expect1(Name,Pid,Data,[Pattern|Patterns],Acc,Rest,EO) -> + case match_lines(Name,Pid,Data,[Pattern],EO) of {match,Match,MatchRest} -> - seq_expect1(MatchRest,Patterns,[Match|Acc],Rest,EO); + seq_expect1(Name,Pid,MatchRest,Patterns,[Match|Acc],Rest,EO); {nomatch,prompt} -> - seq_expect(Rest,[Pattern|Patterns],Acc,EO); + seq_expect(Name,Pid,Rest,[Pattern|Patterns],Acc,EO); {nomatch,NoMatchRest} when Rest==[] -> %% The data did not end with a prompt {continue,[Pattern|Patterns],Acc,NoMatchRest}; {halt,Why,HaltRest} -> {halt,Why,HaltRest++Rest} end; -seq_expect1(Data,[],Acc,Rest,_EO) -> +seq_expect1(_Name,_Pid,Data,[],Acc,Rest,_EO) -> {match,lists:reverse(Acc),Data++Rest}. %% Split prompt-chunk at lines -match_lines(Data,Patterns,EO) -> +match_lines(Name,Pid,Data,Patterns,EO) -> FoundPrompt = EO#eo.found_prompt, case one_line(Data,[]) of {noline,Rest} when FoundPrompt=/=false -> %% This is the line including the prompt - case match_line(Rest,Patterns,FoundPrompt,EO) of + case match_line(Name,Pid,Rest,Patterns,FoundPrompt,EO) of nomatch -> {nomatch,prompt}; {Tag,Match} -> {Tag,Match,[]} end; {noline,Rest} when EO#eo.prompt_check==false -> - case match_line(Rest,Patterns,false,EO) of + case match_line(Name,Pid,Rest,Patterns,false,EO) of nomatch -> {nomatch,Rest}; {Tag,Match} -> @@ -1049,9 +1095,9 @@ match_lines(Data,Patterns,EO) -> {noline,Rest} -> {nomatch,Rest}; {Line,Rest} -> - case match_line(Line,Patterns,false,EO) of + case match_line(Name,Pid,Line,Patterns,false,EO) of nomatch -> - match_lines(Rest,Patterns,EO); + match_lines(Name,Pid,Rest,Patterns,EO); {Tag,Match} -> {Tag,Match,Rest} end @@ -1059,43 +1105,43 @@ match_lines(Data,Patterns,EO) -> %% For one line, match each pattern -match_line(Line,Patterns,FoundPrompt,EO) -> - match_line(Line,Patterns,FoundPrompt,EO,match). - -match_line(Line,[prompt|Patterns],false,EO,RetTag) -> - match_line(Line,Patterns,false,EO,RetTag); -match_line(Line,[prompt|_Patterns],FoundPrompt,_EO,RetTag) -> - try_cont_log(" ~ts", [Line]), - try_cont_log("PROMPT: ~ts", [FoundPrompt]), +match_line(Name,Pid,Line,Patterns,FoundPrompt,EO) -> + match_line(Name,Pid,Line,Patterns,FoundPrompt,EO,match). + +match_line(Name,Pid,Line,[prompt|Patterns],false,EO,RetTag) -> + match_line(Name,Pid,Line,Patterns,false,EO,RetTag); +match_line(Name,Pid,Line,[prompt|_Patterns],FoundPrompt,_EO,RetTag) -> + log(name_or_pid(Name,Pid)," ~ts",[Line]), + log(name_or_pid(Name,Pid),"PROMPT: ~ts",[FoundPrompt]), {RetTag,{prompt,FoundPrompt}}; -match_line(Line,[{prompt,PromptType}|_Patterns],FoundPrompt,_EO,RetTag) +match_line(Name,Pid,Line,[{prompt,PromptType}|_Patterns],FoundPrompt,_EO,RetTag) when PromptType==FoundPrompt -> - try_cont_log(" ~ts", [Line]), - try_cont_log("PROMPT: ~ts", [FoundPrompt]), + log(name_or_pid(Name,Pid)," ~ts",[Line]), + log(name_or_pid(Name,Pid),"PROMPT: ~ts",[FoundPrompt]), {RetTag,{prompt,FoundPrompt}}; -match_line(Line,[{prompt,PromptType}|Patterns],FoundPrompt,EO,RetTag) +match_line(Name,Pid,Line,[{prompt,PromptType}|Patterns],FoundPrompt,EO,RetTag) when PromptType=/=FoundPrompt -> - match_line(Line,Patterns,FoundPrompt,EO,RetTag); -match_line(Line,[{Tag,Pattern}|Patterns],FoundPrompt,EO,RetTag) -> + match_line(Name,Pid,Line,Patterns,FoundPrompt,EO,RetTag); +match_line(Name,Pid,Line,[{Tag,Pattern}|Patterns],FoundPrompt,EO,RetTag) -> case re:run(Line,Pattern,[{capture,all,list}]) of nomatch -> - match_line(Line,Patterns,FoundPrompt,EO,RetTag); + match_line(Name,Pid,Line,Patterns,FoundPrompt,EO,RetTag); {match,Match} -> - try_cont_log("MATCH: ~ts", [Line]), + log(name_or_pid(Name,Pid),"MATCH: ~ts",[Line]), {RetTag,{Tag,Match}} end; -match_line(Line,[Pattern|Patterns],FoundPrompt,EO,RetTag) -> +match_line(Name,Pid,Line,[Pattern|Patterns],FoundPrompt,EO,RetTag) -> case re:run(Line,Pattern,[{capture,all,list}]) of nomatch -> - match_line(Line,Patterns,FoundPrompt,EO,RetTag); + match_line(Name,Pid,Line,Patterns,FoundPrompt,EO,RetTag); {match,Match} -> - try_cont_log("MATCH: ~ts", [Line]), + log(name_or_pid(Name,Pid),"MATCH: ~ts",[Line]), {RetTag,Match} end; -match_line(Line,[],FoundPrompt,EO,match) -> - match_line(Line,EO#eo.haltpatterns,FoundPrompt,EO,halt); -match_line(Line,[],_FoundPrompt,_EO,halt) -> - try_cont_log(" ~ts", [Line]), +match_line(Name,Pid,Line,[],FoundPrompt,EO,match) -> + match_line(Name,Pid,Line,EO#eo.haltpatterns,FoundPrompt,EO,halt); +match_line(Name,Pid,Line,[],_FoundPrompt,_EO,halt) -> + log(name_or_pid(Name,Pid)," ~ts",[Line]), nomatch. one_line([$\n|Rest],Line) -> @@ -1111,26 +1157,29 @@ one_line([],Line) -> debug_log_lines(String) -> Old = put(silent,true), - log_lines(String), + log_lines(undefined,undefined,String), put(silent,Old). -log_lines(String) -> - case log_lines_not_last(String) of +log_lines(Name,Pid,String) -> + case log_lines_not_last(Name,Pid,String) of [] -> ok; LastLine -> - try_cont_log(" ~ts", [LastLine]) + log(name_or_pid(Name,Pid)," ~ts",[LastLine]) end. -log_lines_not_last(String) -> +log_lines_not_last(Name,Pid,String) -> case add_tabs(String,[],[]) of {[],LastLine} -> LastLine; {String1,LastLine} -> - try_cont_log("~ts",[String1]), + log(name_or_pid(Name,Pid),"~ts",[String1]), LastLine end. +name_or_pid(undefined,Pid) -> Pid; +name_or_pid(Name,_) -> Name. + add_tabs([0|Rest],Acc,LastLine) -> add_tabs(Rest,Acc,LastLine); add_tabs([$\r|Rest],Acc,LastLine) -> @@ -1145,8 +1194,6 @@ add_tabs([],[],LastLine) -> {[],lists:reverse(LastLine)}. - - %%% @hidden teln_receive_until_prompt(Pid,Prx,Timeout) -> Fun = fun() -> teln_receive_until_prompt(Pid,Prx,[],[]) end, diff --git a/lib/common_test/src/ct_util.hrl b/lib/common_test/src/ct_util.hrl index 7c01e17c36..a82d58cc42 100644 --- a/lib/common_test/src/ct_util.hrl +++ b/lib/common_test/src/ct_util.hrl @@ -79,4 +79,10 @@ -define(tablesorter_script, "jquery.tablesorter.min.js"). %% Logging information for error handler --record(conn_log, {client, name, address, action, module}). +-record(conn_log, {header=true, + client, + name, + address, + conn_pid, + action, + module}). diff --git a/lib/common_test/src/cth_conn_log.erl b/lib/common_test/src/cth_conn_log.erl index 644594e34d..d5762bada8 100644 --- a/lib/common_test/src/cth_conn_log.erl +++ b/lib/common_test/src/cth_conn_log.erl @@ -56,11 +56,29 @@ pre_init_per_testcase/3, post_end_per_testcase/4]). +%%---------------------------------------------------------------------- +%% Exported types +%%---------------------------------------------------------------------- +-export_type([hook_options/0, + log_type/0, + conn_mod/0]). + +%%---------------------------------------------------------------------- +%% Type declarations +%%---------------------------------------------------------------------- +-type hook_options() :: [hook_option()]. +%% Options that can be given to `cth_conn_log' in the `ct_hook' statement. +-type hook_option() :: {log_type,log_type()} | + {hosts,[ct_gen_conn:key_or_name()]}. +-type log_type() :: raw | pretty | html | silent. +-type conn_mod() :: ct_netconfc | ct_telnet. +%%---------------------------------------------------------------------- + -spec init(Id, HookOpts) -> Result when Id :: term(), - HookOpts :: ct_netconfc:hook_options(), - Result :: {ok,[{ct_netconfc:conn_mod(), - {ct_netconfc:log_type(),[ct_netconfc:key_or_name()]}}]}. + HookOpts :: hook_options(), + Result :: {ok,[{conn_mod(), + {log_type(),[ct_gen_conn:key_or_name()]}}]}. init(_Id, HookOpts) -> ConfOpts = ct:get_config(ct_conn_log,[]), {ok,merge_log_info(ConfOpts,HookOpts)}. @@ -87,6 +105,7 @@ pre_init_per_testcase(TestCase,Config,CthState) -> Logs = lists:map( fun({ConnMod,{LogType,Hosts}}) -> + ct_util:set_testdata({{?MODULE,ConnMod},LogType}), case LogType of LogType when LogType==raw; LogType==pretty -> Dir = ?config(priv_dir,Config), @@ -121,5 +140,6 @@ pre_init_per_testcase(TestCase,Config,CthState) -> {Config,CthState}. post_end_per_testcase(_TestCase,_Config,Return,CthState) -> + [ct_util:delete_testdata({?MODULE,ConnMod}) || {ConnMod,_} <- CthState], error_logger:delete_report_handler(ct_conn_log_h), {Return,CthState}. diff --git a/lib/common_test/src/unix_telnet.erl b/lib/common_test/src/unix_telnet.erl index 88199b07d0..8b24e959e8 100644 --- a/lib/common_test/src/unix_telnet.erl +++ b/lib/common_test/src/unix_telnet.erl @@ -54,8 +54,8 @@ -compile(export_all). %% Callbacks for ct_telnet.erl --export([connect/5,get_prompt_regexp/0]). --import(ct_telnet,[start_log/1,cont_log/2,end_log/0]). +-export([connect/6,get_prompt_regexp/0]). +-import(ct_telnet,[start_gen_log/1,log/4,end_gen_log/0]). -define(username,"login: "). -define(password,"Password: "). @@ -76,7 +76,9 @@ get_prompt_regexp() -> %%%----------------------------------------------------------------- %%% @hidden -%%% @spec connect(Ip,Port,Timeout,KeepAlive,Extra) -> {ok,Handle} | {error,Reason} +%%% @spec connect(ConnName,Ip,Port,Timeout,KeepAlive,Extra) -> +%%% {ok,Handle} | {error,Reason} +%%% ConnName = ct:target_name() %%% Ip = string() | {integer(),integer(),integer(),integer()} %%% Port = integer() %%% Timeout = integer() @@ -89,59 +91,68 @@ get_prompt_regexp() -> %%% @doc Callback for ct_telnet.erl. %%% %%%

Setup telnet connection to a UNIX host.

-connect(Ip,Port,Timeout,KeepAlive,Extra) -> +connect(ConnName,Ip,Port,Timeout,KeepAlive,Extra) -> case Extra of {Username,Password} -> - connect1(Ip,Port,Timeout,KeepAlive,Username,Password); - Name -> - case get_username_and_password(Name) of + connect1(ConnName,Ip,Port,Timeout,KeepAlive, + Username,Password); + KeyOrName -> + case get_username_and_password(KeyOrName) of {ok,{Username,Password}} -> - connect1(Ip,Port,Timeout,KeepAlive,Username,Password); + connect1(ConnName,Ip,Port,Timeout,KeepAlive, + Username,Password); Error -> Error end end. -connect1(Ip,Port,Timeout,KeepAlive,Username,Password) -> - start_log("unix_telnet:connect"), +connect1(Name,Ip,Port,Timeout,KeepAlive,Username,Password) -> + start_gen_log("unix_telnet connect"), Result = case ct_telnet_client:open(Ip,Port,Timeout,KeepAlive) of {ok,Pid} -> - case ct_telnet:silent_teln_expect(Pid,[],[prompt],?prx,[]) of + case ct_telnet:silent_teln_expect(Name,Pid,[], + [prompt],?prx,[]) of {ok,{prompt,?username},_} -> + log(Name,send,"Logging in to ~p:~p", [Ip,Port]), ok = ct_telnet_client:send_data(Pid,Username), - cont_log("Username: ~ts",[Username]), - case ct_telnet:silent_teln_expect(Pid,[],prompt,?prx,[]) of + log(Name,send,"Username: ~ts",[Username]), + case ct_telnet:silent_teln_expect(Name,Pid,[], + prompt,?prx,[]) of {ok,{prompt,?password},_} -> ok = ct_telnet_client:send_data(Pid,Password), Stars = lists:duplicate(length(Password),$*), - cont_log("Password: ~s",[Stars]), + log(Name,send,"Password: ~s",[Stars]), ok = ct_telnet_client:send_data(Pid,""), - case ct_telnet:silent_teln_expect(Pid,[],prompt, + case ct_telnet:silent_teln_expect(Name,Pid,[], + prompt, ?prx,[]) of {ok,{prompt,Prompt},_} - when Prompt=/=?username, Prompt=/=?password -> + when Prompt=/=?username, + Prompt=/=?password -> {ok,Pid}; Error -> - cont_log("Password failed\n~p\n", - [Error]), + log(Name,recv,"Password failed\n~p\n", + [Error]), {error,Error} end; Error -> - cont_log("Login failed\n~p\n",[Error]), + log(Name,recv,"Login failed\n~p\n",[Error]), {error,Error} end; {ok,[{prompt,_OtherPrompt1},{prompt,_OtherPrompt2}],_} -> {ok,Pid}; Error -> - cont_log("Did not get expected prompt\n~p\n",[Error]), + log(Name,error, + "Did not get expected prompt\n~p\n",[Error]), {error,Error} end; Error -> - cont_log("Could not open telnet connection\n~p\n",[Error]), + log(Name,error, + "Could not open telnet connection\n~p\n",[Error]), Error end, - end_log(), + end_gen_log(), Result. get_username_and_password(Name) -> -- cgit v1.2.3 From da730dc3f7a6e46c0341146a69871934d07120e0 Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Wed, 22 Jan 2014 16:19:00 +0100 Subject: Add and improve test cases Also correct some issues found during test --- lib/common_test/src/ct_conn_log_h.erl | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) (limited to 'lib/common_test/src') diff --git a/lib/common_test/src/ct_conn_log_h.erl b/lib/common_test/src/ct_conn_log_h.erl index 550f62f4c1..286844d526 100644 --- a/lib/common_test/src/ct_conn_log_h.erl +++ b/lib/common_test/src/ct_conn_log_h.erl @@ -200,8 +200,13 @@ pretty_head({{{Y,Mo,D},{H,Mi,S}},MicroS},ConnMod,Text0) -> micro2milli(MicroS)]). pretty_title(#conn_log{client=Client}=Info) -> - io_lib:format("= Client ~w ~s Server ~ts ", - [Client,actionstr(Info),serverstr(Info)]). + case actionstr(Info) of + {no_server,Action} -> + io_lib:format("= Client ~w ~s ",[Client,Action]); + Action -> + io_lib:format("= Client ~w ~s ~ts ",[Client,Action, + serverstr(Info)]) + end. actionstr(#conn_log{action=send}) -> "----->"; actionstr(#conn_log{action=cmd}) -> "----->"; -- cgit v1.2.3 From f40f4686848bbabb9357b33d08d4b4039d9d7c63 Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Fri, 24 Jan 2014 12:19:05 +0100 Subject: Implement tests for logging traffic for multiple telnet connections Also fix remaining problems in source code --- lib/common_test/src/ct_conn_log_h.erl | 28 ++++++++-------------------- lib/common_test/src/ct_telnet.erl | 10 +++++----- lib/common_test/src/unix_telnet.erl | 8 +++++--- 3 files changed, 18 insertions(+), 28 deletions(-) (limited to 'lib/common_test/src') diff --git a/lib/common_test/src/ct_conn_log_h.erl b/lib/common_test/src/ct_conn_log_h.erl index 286844d526..6e0e0baab2 100644 --- a/lib/common_test/src/ct_conn_log_h.erl +++ b/lib/common_test/src/ct_conn_log_h.erl @@ -52,7 +52,7 @@ open_files([],State) -> do_open_files([{Tag,File}|Logs],Acc) -> - case file:open(File, [write,{encoding,utf8}]) of + case file:open(File, [write,append,{encoding,utf8}]) of {ok,Fd} -> do_open_files(Logs,[{Tag,Fd}|Acc]); {error,Reason} -> @@ -63,17 +63,12 @@ do_open_files([],Acc) -> handle_event({_Type, GL, _Msg}, State) when node(GL) /= node() -> {ok, State}; -handle_event({_Type,_GL,{Pid,{ct_connection,Action,ConnName},Report}},State) -> - %% NOTE: if the format of this event is changed - %% ({ct_connection,Action,ConnName}) then remember to change - %% test_server_h:report_receiver as well!!! - Info = conn_info(Pid,#conn_log{name=ConnName,action=Action}), +handle_event({_Type,_GL,{Pid,{ct_connection,Mod,Action,ConnName},Report}}, + State) -> + Info = conn_info(Pid,#conn_log{name=ConnName,action=Action,module=Mod}), write_report(now(),Info,Report,State), {ok, State}; handle_event({_Type,_GL,{Pid,Info=#conn_log{},Report}},State) -> - %% NOTE: if the format of this event is changed - %% (Info=#conn_log{}) then remember to change - %% test_server_h:report_receiver as well!!! write_report(now(),conn_info(Pid,Info),Report,State), {ok, State}; handle_event({error_report,_,{Pid,_,[{ct_connection,ConnName}|R]}},State) -> @@ -151,12 +146,7 @@ format_head(ConnMod,_,Time,Text) -> io_lib:format("~n~ts",[Head]). format_title(raw,#conn_log{client=Client}=Info) -> - case actionstr(Info) of - {no_server,Action} -> - io_lib:format("Client ~w ~s",[Client,Action]); - Action -> - io_lib:format("Client ~w ~s ~ts",[Client,Action,serverstr(Info)]) - end; + io_lib:format("Client ~w ~s ~ts",[Client,actionstr(Info),serverstr(Info)]); format_title(_,Info) -> Title = pad_char_end(?WIDTH,pretty_title(Info),$=), io_lib:format("~n~ts", [Title]). @@ -211,10 +201,8 @@ pretty_title(#conn_log{client=Client}=Info) -> actionstr(#conn_log{action=send}) -> "----->"; actionstr(#conn_log{action=cmd}) -> "----->"; actionstr(#conn_log{action=recv}) -> "<-----"; -actionstr(#conn_log{action=open}) -> "open session to"; -actionstr(#conn_log{action=close}) -> "close session to"; -actionstr(#conn_log{action=info}) -> {no_server,"info"}; -actionstr(#conn_log{action=error}) -> {no_server,"error"}; +actionstr(#conn_log{action=open}) -> "opened session to"; +actionstr(#conn_log{action=close}) -> "closed session to"; actionstr(_) -> "<---->". serverstr(#conn_log{name=undefined,address={undefined,_}}) -> @@ -222,7 +210,7 @@ serverstr(#conn_log{name=undefined,address={undefined,_}}) -> serverstr(#conn_log{name=undefined,address=Address}) -> io_lib:format("~p",[Address]); serverstr(#conn_log{name=Alias,address={undefined,_}}) -> - io_lib:format("~w()",[Alias]); + io_lib:format("~w",[Alias]); serverstr(#conn_log{name=Alias,address=Address}) -> io_lib:format("~w(~p)",[Alias,Address]). diff --git a/lib/common_test/src/ct_telnet.erl b/lib/common_test/src/ct_telnet.erl index 5fc89be0c5..f9dd62ee37 100644 --- a/lib/common_test/src/ct_telnet.erl +++ b/lib/common_test/src/ct_telnet.erl @@ -181,7 +181,7 @@ open(KeyOrName,ConnType,TargetMod,Extra) -> end; Bool -> Bool end, - log(undefined,open,"Opening connection ~p to ~p", + log(undefined,open,"Connecting to ~p(~p)", [KeyOrName,Addr1]), ct_gen_conn:start(KeyOrName,full_addr(Addr1,ConnType), {TargetMod,KeepAlive,Extra},?MODULE) @@ -200,7 +200,7 @@ open(KeyOrName,ConnType,TargetMod,Extra) -> close(Connection) -> case get_handle(Connection) of {ok,Pid} -> - log(undefined,close,"Closing connection for handle: ~w",[Pid]), + log(undefined,close,"Connection closed, handle: ~w",[Pid]), case ct_gen_conn:stop(Pid) of {error,{process_down,Pid,noproc}} -> {error,already_closed}; @@ -600,9 +600,9 @@ reconnect(Ip,Port,N,State=#state{name=Name, %% @hidden terminate(TelnPid,State) -> - log(State,close,"Closing telnet connection.\nId: ~w",[TelnPid]), - ct_telnet_client:close(TelnPid). - + Result = ct_telnet_client:close(TelnPid), + log(State,close,"Telnet connection for ~w closed.",[TelnPid]), + Result. %%%================================================================= %%% Internal function diff --git a/lib/common_test/src/unix_telnet.erl b/lib/common_test/src/unix_telnet.erl index 8b24e959e8..e049c3bf39 100644 --- a/lib/common_test/src/unix_telnet.erl +++ b/lib/common_test/src/unix_telnet.erl @@ -137,19 +137,21 @@ connect1(Name,Ip,Port,Timeout,KeepAlive,Username,Password) -> {error,Error} end; Error -> - log(Name,recv,"Login failed\n~p\n",[Error]), + log(Name,recv,"Login to ~p:~p failed\n~p\n",[Ip,Port,Error]), {error,Error} end; {ok,[{prompt,_OtherPrompt1},{prompt,_OtherPrompt2}],_} -> {ok,Pid}; Error -> log(Name,error, - "Did not get expected prompt\n~p\n",[Error]), + "Did not get expected prompt from ~p:~p\n~p\n", + [Ip,Port,Error]), {error,Error} end; Error -> log(Name,error, - "Could not open telnet connection\n~p\n",[Error]), + "Could not open telnet connection to ~p:~p\n~p\n", + [Ip,Port,Error]), Error end, end_gen_log(), -- cgit v1.2.3 From 95a574b3620ec3d7420c7807b2d84f4602512229 Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Mon, 27 Jan 2014 14:05:44 +0100 Subject: Make it possible to use raw telnet logs in parallel test case groups --- lib/common_test/src/ct_conn_log_h.erl | 84 +++++++++++++++++++++-------------- lib/common_test/src/ct_util.erl | 11 +++-- lib/common_test/src/cth_conn_log.erl | 61 ++++++++++++++++++++++--- 3 files changed, 114 insertions(+), 42 deletions(-) (limited to 'lib/common_test/src') diff --git a/lib/common_test/src/ct_conn_log_h.erl b/lib/common_test/src/ct_conn_log_h.erl index 6e0e0baab2..2b83ff1abb 100644 --- a/lib/common_test/src/ct_conn_log_h.erl +++ b/lib/common_test/src/ct_conn_log_h.erl @@ -30,79 +30,90 @@ handle_event/2, handle_call/2, handle_info/2, terminate/2]). --record(state, {group_leader,logs=[]}). +-record(state, {logs=[], default_gl}). -define(WIDTH,80). %%%----------------------------------------------------------------- %%% Callbacks -init({GL,Logs}) -> - open_files(Logs,#state{group_leader=GL}). +init({GL,ConnLogs}) -> + open_files(GL,ConnLogs,#state{default_gl=GL}). -open_files([{ConnMod,{LogType,Logs}}|T],State) -> - case do_open_files(Logs,[]) of +open_files(GL,[{ConnMod,{LogType,ConnLogs}}|T],State) -> + case do_open_files(GL,ConnLogs,[]) of {ok,Fds} -> - open_files(T,State#state{logs=[{ConnMod,{LogType,Fds}} | - State#state.logs]}); + open_files(GL,T,State#state{logs=[{GL,[{ConnMod,{LogType,Fds}}]} | + State#state.logs]}); Error -> Error end; -open_files([],State) -> +open_files(_GL,[],State) -> {ok,State}. - -do_open_files([{Tag,File}|Logs],Acc) -> +do_open_files(GL,[{Tag,File}|ConnLogs],Acc) -> case file:open(File, [write,append,{encoding,utf8}]) of {ok,Fd} -> - do_open_files(Logs,[{Tag,Fd}|Acc]); + do_open_files(GL,ConnLogs,[{Tag,Fd}|Acc]); {error,Reason} -> {error,{could_not_open_log,File,Reason}} end; -do_open_files([],Acc) -> +do_open_files(_GL,[],Acc) -> {ok,lists:reverse(Acc)}. +handle_event({info_report,_,{From,update,{GL,ConnLogs}}}, + State) when node(GL) == node() -> + + %%! --- Tue Jan 28 12:18:50 2014 --- peppe was here! + io:format(user, "!!! ADDING NEW LOGS FOR ~p~n", [GL]), + + open_files(GL,ConnLogs,#state{}), + From ! {updated,GL}, + {ok, State}; handle_event({_Type, GL, _Msg}, State) when node(GL) /= node() -> {ok, State}; -handle_event({_Type,_GL,{Pid,{ct_connection,Mod,Action,ConnName},Report}}, +handle_event({_Type,GL,{Pid,{ct_connection,Mod,Action,ConnName},Report}}, State) -> Info = conn_info(Pid,#conn_log{name=ConnName,action=Action,module=Mod}), - write_report(now(),Info,Report,State), + write_report(now(),Info,Report,GL,State), {ok, State}; -handle_event({_Type,_GL,{Pid,Info=#conn_log{},Report}},State) -> - write_report(now(),conn_info(Pid,Info),Report,State), +handle_event({_Type,GL,{Pid,Info=#conn_log{},Report}}, State) -> + write_report(now(),conn_info(Pid,Info),Report,GL,State), {ok, State}; -handle_event({error_report,_,{Pid,_,[{ct_connection,ConnName}|R]}},State) -> +handle_event({error_report,GL,{Pid,_,[{ct_connection,ConnName}|R]}}, State) -> %% Error reports from connection - write_error(now(),conn_info(Pid,#conn_log{name=ConnName}),R,State), + write_error(now(),conn_info(Pid,#conn_log{name=ConnName}),R,GL,State), {ok, State}; -handle_event(_, State) -> +handle_event(_What, State) -> {ok, State}. -handle_info(_, State) -> +handle_info(_What, State) -> {ok, State}. handle_call(_Query, State) -> {ok, {error, bad_query}, State}. terminate(_,#state{logs=Logs}) -> - [file:close(Fd) || {_,{_,Fds}} <- Logs, {_,Fd} <- Fds], + lists:foreach( + fun({_GL,ConnLogs}) -> + [file:close(Fd) || {_,{_,Fds}} <- ConnLogs, {_,Fd} <- Fds] + end, Logs), ok. %%%----------------------------------------------------------------- %%% Writing reports -write_report(_Time,#conn_log{header=false,module=ConnMod}=Info,Data,State) -> - {LogType,Fd} = get_log(Info,State), +write_report(_Time,#conn_log{header=false,module=ConnMod}=Info,Data,GL,State) -> + {LogType,Fd} = get_log(Info,GL,State), io:format(Fd,"~n~ts",[format_data(ConnMod,LogType,Data)]); -write_report(Time,#conn_log{module=ConnMod}=Info,Data,State) -> - {LogType,Fd} = get_log(Info,State), +write_report(Time,#conn_log{module=ConnMod}=Info,Data,GL,State) -> + {LogType,Fd} = get_log(Info,GL,State), io:format(Fd,"~n~ts~ts~ts",[format_head(ConnMod,LogType,Time), format_title(LogType,Info), format_data(ConnMod,LogType,Data)]). -write_error(Time,#conn_log{module=ConnMod}=Info,Report,State) -> - case get_log(Info,State) of +write_error(Time,#conn_log{module=ConnMod}=Info,Report,GL,State) -> + case get_log(Info,GL,State) of {html,_} -> %% The error will anyway be written in the html log by the %% sasl error handler, so don't write it again. @@ -114,14 +125,19 @@ write_error(Time,#conn_log{module=ConnMod}=Info,Report,State) -> format_error(LogType,Report)]) end. -get_log(Info,State) -> - case proplists:get_value(Info#conn_log.module,State#state.logs) of - {html,_} -> - {html,State#state.group_leader}; - {LogType,Fds} -> - {LogType,get_fd(Info,Fds)}; +get_log(Info,GL,State) -> + case proplists:get_value(GL, State#state.logs) of undefined -> - {html,State#state.group_leader} + {html,State#state.default_gl}; + ConnLogs -> + case proplists:get_value(Info#conn_log.module,ConnLogs) of + {html,_} -> + {html,GL}; + {LogType,Fds} -> + {LogType,get_fd(Info,Fds)}; + undefined -> + {html,GL} + end end. get_fd(#conn_log{name=undefined},Fds) -> diff --git a/lib/common_test/src/ct_util.erl b/lib/common_test/src/ct_util.erl index bcc4caa62e..1d851f8d2f 100644 --- a/lib/common_test/src/ct_util.erl +++ b/lib/common_test/src/ct_util.erl @@ -382,9 +382,14 @@ loop(Mode,TestData,StartDir) -> TestData1 = case lists:keysearch(Key,1,TestData) of {value,{Key,Val}} -> - NewVal = Fun(Val), - return(From,NewVal), - [{Key,NewVal}|lists:keydelete(Key,1,TestData)]; + case Fun(Val) of + '$delete' -> + return(From,deleted), + lists:keydelete(Key,1,TestData); + NewVal -> + return(From,NewVal), + [{Key,NewVal}|lists:keydelete(Key,1,TestData)] + end; _ -> case lists:member(create,Opts) of true -> diff --git a/lib/common_test/src/cth_conn_log.erl b/lib/common_test/src/cth_conn_log.erl index d5762bada8..050bda6eda 100644 --- a/lib/common_test/src/cth_conn_log.erl +++ b/lib/common_test/src/cth_conn_log.erl @@ -104,7 +104,7 @@ get_log_opts(Opts) -> pre_init_per_testcase(TestCase,Config,CthState) -> Logs = lists:map( - fun({ConnMod,{LogType,Hosts}}) -> + fun({ConnMod,{LogType,Hosts}}) -> ct_util:set_testdata({{?MODULE,ConnMod},LogType}), case LogType of LogType when LogType==raw; LogType==pretty -> @@ -136,10 +136,61 @@ pre_init_per_testcase(TestCase,Config,CthState) -> end end, CthState), - error_logger:add_report_handler(ct_conn_log_h,{group_leader(),Logs}), + + GL = group_leader(), + Update = + fun(Init) when Init == undefined; Init == [] -> + + %%! --- Tue Jan 28 12:13:08 2014 --- peppe was here! + io:format(user, "### ~p: ADDING NEW HANDLER FOR ~p~n", + [TestCase,GL]), + + error_logger:add_report_handler(ct_conn_log_h,{GL,Logs}), + [TestCase]; + (PrevUsers) -> + + %%! --- Tue Jan 28 12:13:08 2014 --- peppe was here! + io:format(user, "### ~p: CONNECTING ~p TO EXISTING HANDLER~n", + [TestCase,GL]), + + error_logger:info_report(update,{GL,Logs}), + receive + {updated,GL} -> + [TestCase|PrevUsers] + after + 5000 -> + {error,no_response} + end + end, + ct_util:update_testdata(?MODULE, Update, [create]), {Config,CthState}. -post_end_per_testcase(_TestCase,_Config,Return,CthState) -> - [ct_util:delete_testdata({?MODULE,ConnMod}) || {ConnMod,_} <- CthState], - error_logger:delete_report_handler(ct_conn_log_h), +post_end_per_testcase(TestCase,_Config,Return,CthState) -> + Update = + fun(PrevUsers) -> + case lists:delete(TestCase, PrevUsers) of + [] -> + '$delete'; + PrevUsers1 -> + PrevUsers1 + end + end, + case ct_util:update_testdata(?MODULE, Update) of + deleted -> + [ct_util:delete_testdata({?MODULE,ConnMod}) || + {ConnMod,_} <- CthState], + + %%! --- Tue Jan 28 13:29:37 2014 --- peppe was here! + io:format(user, "### ~p: REMOVING ERROR LOGGER~n", [TestCase]), + + error_logger:delete_report_handler(ct_conn_log_h); + {error,no_response} -> + exit({?MODULE,no_response_from_logger}); + _PrevUsers -> + %%! --- Tue Jan 28 13:29:37 2014 --- peppe was here! + io:format(user, "### ~p: *NOT* REMOVING ERROR LOGGER~n", [TestCase]), + + ok + end, {Return,CthState}. + -- cgit v1.2.3 From c5079569ec2c6248f702b15c0e95def24411ca3c Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Tue, 28 Jan 2014 19:01:07 +0100 Subject: Fix remaining problems using raw telnet logging for parallel test cases --- lib/common_test/src/ct_conn_log_h.erl | 26 ++++----- lib/common_test/src/ct_telnet.erl | 101 +++++++++++++++++++++++++++++++++- lib/common_test/src/cth_conn_log.erl | 17 ------ 3 files changed, 112 insertions(+), 32 deletions(-) (limited to 'lib/common_test/src') diff --git a/lib/common_test/src/ct_conn_log_h.erl b/lib/common_test/src/ct_conn_log_h.erl index 2b83ff1abb..d733df27dc 100644 --- a/lib/common_test/src/ct_conn_log_h.erl +++ b/lib/common_test/src/ct_conn_log_h.erl @@ -39,36 +39,34 @@ init({GL,ConnLogs}) -> open_files(GL,ConnLogs,#state{default_gl=GL}). -open_files(GL,[{ConnMod,{LogType,ConnLogs}}|T],State) -> - case do_open_files(GL,ConnLogs,[]) of +open_files(GL,[{ConnMod,{LogType,LogFiles}}|T],State=#state{logs=Logs}) -> + case do_open_files(LogFiles,[]) of {ok,Fds} -> - open_files(GL,T,State#state{logs=[{GL,[{ConnMod,{LogType,Fds}}]} | - State#state.logs]}); + ConnInfo = proplists:get_value(GL,Logs,[]), + Logs1 = [{GL,[{ConnMod,{LogType,Fds}}|ConnInfo]} | + proplists:delete(GL,Logs)], + open_files(GL,T,State#state{logs=Logs1}); Error -> Error end; open_files(_GL,[],State) -> {ok,State}. -do_open_files(GL,[{Tag,File}|ConnLogs],Acc) -> +do_open_files([{Tag,File}|LogFiles],Acc) -> case file:open(File, [write,append,{encoding,utf8}]) of {ok,Fd} -> - do_open_files(GL,ConnLogs,[{Tag,Fd}|Acc]); + do_open_files(LogFiles,[{Tag,Fd}|Acc]); {error,Reason} -> {error,{could_not_open_log,File,Reason}} end; -do_open_files(_GL,[],Acc) -> +do_open_files([],Acc) -> {ok,lists:reverse(Acc)}. handle_event({info_report,_,{From,update,{GL,ConnLogs}}}, State) when node(GL) == node() -> - - %%! --- Tue Jan 28 12:18:50 2014 --- peppe was here! - io:format(user, "!!! ADDING NEW LOGS FOR ~p~n", [GL]), - - open_files(GL,ConnLogs,#state{}), + Result = open_files(GL,ConnLogs,State), From ! {updated,GL}, - {ok, State}; + Result; handle_event({_Type, GL, _Msg}, State) when node(GL) /= node() -> {ok, State}; handle_event({_Type,GL,{Pid,{ct_connection,Mod,Action,ConnName},Report}}, @@ -126,7 +124,7 @@ write_error(Time,#conn_log{module=ConnMod}=Info,Report,GL,State) -> end. get_log(Info,GL,State) -> - case proplists:get_value(GL, State#state.logs) of + case proplists:get_value(GL,State#state.logs) of undefined -> {html,State#state.default_gl}; ConnLogs -> diff --git a/lib/common_test/src/ct_telnet.erl b/lib/common_test/src/ct_telnet.erl index f9dd62ee37..698915b37c 100644 --- a/lib/common_test/src/ct_telnet.erl +++ b/lib/common_test/src/ct_telnet.erl @@ -42,7 +42,106 @@ %%%

Enter the telnet_settings term in a configuration %%% file included in the test and ct_telnet will retrieve the information %%% automatically. Note that keep_alive may be specified per connection if -%%% required. See unix_telnet for details.

+%%% required. See unix_telnet for details.

+%%% +%%% @end +%%% +%%% == Logging == +%%% +%%% `ct_telnet' can be configured to uses the `error_logger' for logging telnet +%%% traffic. A special purpose error handler is implemented in +%%% `ct_conn_log_h'. To use this error handler, add the `cth_conn_log' +%%% hook in your test suite, e.g. +%%% +%%% +%%% ``` +%%% suite() -> +%%% [{ct_hooks, [{cth_conn_log, [{conn_mod(),hook_options()}]}]}]. +%%%''' +%%% +%%% `conn_mod()' is the name of the common_test module implementing +%%% the connection protocol, i.e. `ct_telnet'. +%%% +%%% The hook option `log_type' specifies the type of logging: +%%% +%%%
+%%%
`raw'
+%%%
The sent and received telnet data is logged to a separate +%%% text file as is without any formatting. A link to the file is +%%% added to the test case HTML log.
+%%% +%%%
`html (default)'
+%%%
The sent and received telnet traffic is pretty printed +%%% directly in the test case HTML log.
+%%% +%%%
`silent'
+%%%
Telnet traffic is not logged.
+%%%
+%%% +%%% By default, all telnet traffic is logged in one single log +%%% file. However, it is possible to have different connections logged +%%% in separate files. To do this, use the hook option `hosts' and +%%% list the names of the servers/connections that will be used in the +%%% suite. Note that the connections must be named for this to work. +%%% +%%% The `hosts' option has no effect if `log_type' is set to `html' or +%%% `silent'. +%%% +%%% The hook options can also be specified in a configuration file with +%%% the configuration variable `ct_conn_log': +%%% +%%% ``` +%%% {ct_conn_log,[{conn_mod(),hook_options()}]}. +%%% ''' +%%% +%%% For example: +%% +%%% ``` +%%% {ct_conn_log,[{ct_telnet,[{log_type,raw}, +%%% {hosts,[key_or_name()]}]}]} +%%% ''' +%%% +%%% Note that hook options specified in a configuration file +%%% will overwrite any hardcoded hook options in the test suite. +%% +%%% === Logging example 1 === +%%% +%%% The following `ct_hooks' statement will cause raw printing of +%%% telnet traffic to separate logs for the connections named +%%% `server1' and `server2'. Any other connections will be logged +%%% to default telnet log. +%%% +%%% ``` +%%% suite() -> +%%% [{ct_hooks, [{cth_conn_log, [{ct_telnet,[{log_type,raw}}, +%%% {hosts,[server1,server2]}]} +%%% ]}]}]. +%%%''' +%%% +%%% === Logging example 2 === +%%% +%%% The following configuration file will cause raw logging of all +%%% telnet traffic into one single text file. +%%% +%%% ``` +%%% {ct_conn_log,[{ct_telnet,[{log_type,raw}]}]}. +%%% ''' +%%% +%%% The `ct_hooks' statement must look like this: +%%% +%%% ``` +%%% suite() -> +%%% [{ct_hooks, [{cth_conn_log, []}]}]. +%%% ''' +%%% +%%% The same `ct_hooks' statement without the configuration file would +%%% cause HTML logging of all telnet connections into the test case +%%% HTML log. +%%% +%%% Note that if the `cth_conn_log' hook is not added, telnet +%%% traffic is still logged in the test case log files (on the legacy +%%% `ct_telnet' format). + %%% @type connection_type() = telnet | ts1 | ts2 diff --git a/lib/common_test/src/cth_conn_log.erl b/lib/common_test/src/cth_conn_log.erl index 050bda6eda..a731c8054c 100644 --- a/lib/common_test/src/cth_conn_log.erl +++ b/lib/common_test/src/cth_conn_log.erl @@ -140,19 +140,9 @@ pre_init_per_testcase(TestCase,Config,CthState) -> GL = group_leader(), Update = fun(Init) when Init == undefined; Init == [] -> - - %%! --- Tue Jan 28 12:13:08 2014 --- peppe was here! - io:format(user, "### ~p: ADDING NEW HANDLER FOR ~p~n", - [TestCase,GL]), - error_logger:add_report_handler(ct_conn_log_h,{GL,Logs}), [TestCase]; (PrevUsers) -> - - %%! --- Tue Jan 28 12:13:08 2014 --- peppe was here! - io:format(user, "### ~p: CONNECTING ~p TO EXISTING HANDLER~n", - [TestCase,GL]), - error_logger:info_report(update,{GL,Logs}), receive {updated,GL} -> @@ -179,17 +169,10 @@ post_end_per_testcase(TestCase,_Config,Return,CthState) -> deleted -> [ct_util:delete_testdata({?MODULE,ConnMod}) || {ConnMod,_} <- CthState], - - %%! --- Tue Jan 28 13:29:37 2014 --- peppe was here! - io:format(user, "### ~p: REMOVING ERROR LOGGER~n", [TestCase]), - error_logger:delete_report_handler(ct_conn_log_h); {error,no_response} -> exit({?MODULE,no_response_from_logger}); _PrevUsers -> - %%! --- Tue Jan 28 13:29:37 2014 --- peppe was here! - io:format(user, "### ~p: *NOT* REMOVING ERROR LOGGER~n", [TestCase]), - ok end, {Return,CthState}. -- cgit v1.2.3 From f8af45981ec188e95205233f2df9e5e596139fac Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Tue, 28 Jan 2014 19:47:41 +0100 Subject: Make temporary fix of problem that sometimes causes the ct_util server to die --- lib/common_test/src/ct_framework.erl | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) (limited to 'lib/common_test/src') diff --git a/lib/common_test/src/ct_framework.erl b/lib/common_test/src/ct_framework.erl index e81b69a1b5..54510a657a 100644 --- a/lib/common_test/src/ct_framework.erl +++ b/lib/common_test/src/ct_framework.erl @@ -730,9 +730,14 @@ end_tc(Mod,Func,TCPid,Result,Args,Return) -> (undefined) -> undefined; (Unexpected) -> - exit({error,{reset_curr_tc,{Mod,Func},Unexpected}}) + {error,{reset_curr_tc,{Mod,Func},Unexpected}} end, - ct_util:update_testdata(curr_tc, ClearCurrTC), + case ct_util:update_testdata(curr_tc, ClearCurrTC) of + {error,_} = ClearError -> + exit(ClearError); + _ -> + ok + end, case FinalResult of {auto_skip,{sequence_failed,_,_}} -> -- cgit v1.2.3 From bf6c2ff6625c45bc6c65c112719879078292ee22 Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Wed, 29 Jan 2014 09:39:04 +0100 Subject: Add documentation about logging in the ct_telnet module --- lib/common_test/src/ct_telnet.erl | 267 +++++++++++++++++++------------------- 1 file changed, 133 insertions(+), 134 deletions(-) (limited to 'lib/common_test/src') diff --git a/lib/common_test/src/ct_telnet.erl b/lib/common_test/src/ct_telnet.erl index 698915b37c..b4d82a53cf 100644 --- a/lib/common_test/src/ct_telnet.erl +++ b/lib/common_test/src/ct_telnet.erl @@ -17,146 +17,145 @@ %% %CopyrightEnd% %% -%%% @doc Common Test specific layer on top of telnet client ct_telnet_client.erl -%%% -%%%

Use this module to set up telnet connections, send commands and -%%% perform string matching on the result. -%%% See the unix_telnet manual page for information about how to use -%%% ct_telnet, and configure connections, specifically for unix hosts.

-%%%

The following default values are defined in ct_telnet:

-%%%
-%%% Connection timeout = 10 sec (time to wait for connection)
-%%% Command timeout = 10 sec (time to wait for a command to return)
-%%% Max no of reconnection attempts = 3
-%%% Reconnection interval = 5 sek (time to wait in between reconnection attempts)
-%%% Keep alive = true (will send NOP to the server every 10 sec if connection is idle)
-%%%

These parameters can be altered by the user with the following -%%% configuration term:

-%%%
-%%% {telnet_settings, [{connect_timeout,Millisec},
-%%%                    {command_timeout,Millisec},
-%%%                    {reconnection_attempts,N},
-%%%                    {reconnection_interval,Millisec},
-%%%                    {keep_alive,Bool}]}.
-%%%

Millisec = integer(), N = integer()

-%%%

Enter the telnet_settings term in a configuration -%%% file included in the test and ct_telnet will retrieve the information -%%% automatically. Note that keep_alive may be specified per connection if -%%% required. See unix_telnet for details.

-%%% -%%% @end -%%% -%%% == Logging == -%%% -%%% `ct_telnet' can be configured to uses the `error_logger' for logging telnet -%%% traffic. A special purpose error handler is implemented in -%%% `ct_conn_log_h'. To use this error handler, add the `cth_conn_log' -%%% hook in your test suite, e.g. -%%% -%%% -%%% ``` -%%% suite() -> -%%% [{ct_hooks, [{cth_conn_log, [{conn_mod(),hook_options()}]}]}]. -%%%''' -%%% -%%% `conn_mod()' is the name of the common_test module implementing -%%% the connection protocol, i.e. `ct_telnet'. -%%% -%%% The hook option `log_type' specifies the type of logging: -%%% -%%%
-%%%
`raw'
-%%%
The sent and received telnet data is logged to a separate -%%% text file as is without any formatting. A link to the file is -%%% added to the test case HTML log.
-%%% -%%%
`html (default)'
-%%%
The sent and received telnet traffic is pretty printed -%%% directly in the test case HTML log.
-%%% -%%%
`silent'
-%%%
Telnet traffic is not logged.
-%%%
-%%% -%%% By default, all telnet traffic is logged in one single log -%%% file. However, it is possible to have different connections logged -%%% in separate files. To do this, use the hook option `hosts' and -%%% list the names of the servers/connections that will be used in the -%%% suite. Note that the connections must be named for this to work. -%%% -%%% The `hosts' option has no effect if `log_type' is set to `html' or -%%% `silent'. -%%% -%%% The hook options can also be specified in a configuration file with -%%% the configuration variable `ct_conn_log': -%%% -%%% ``` -%%% {ct_conn_log,[{conn_mod(),hook_options()}]}. -%%% ''' -%%% -%%% For example: +%% @doc Common Test specific layer on top of telnet client `ct_telnet_client.erl' %% -%%% ``` -%%% {ct_conn_log,[{ct_telnet,[{log_type,raw}, -%%% {hosts,[key_or_name()]}]}]} -%%% ''' -%%% -%%% Note that hook options specified in a configuration file -%%% will overwrite any hardcoded hook options in the test suite. +%%

Use this module to set up telnet connections, send commands and +%% perform string matching on the result. +%% See the `unix_telnet' manual page for information about how to use +%% `ct_telnet', and configure connections, specifically for unix hosts.

+%%

The following default values are defined in `ct_telnet':

+%%
+%% Connection timeout = 10 sec (time to wait for connection)
+%% Command timeout = 10 sec (time to wait for a command to return)
+%% Max no of reconnection attempts = 3
+%% Reconnection interval = 5 sek (time to wait in between reconnection attempts)
+%% Keep alive = true (will send NOP to the server every 10 sec if connection is idle)
+%%

These parameters can be altered by the user with the following +%% configuration term:

+%%
+%% {telnet_settings, [{connect_timeout,Millisec},
+%%                    {command_timeout,Millisec},
+%%                    {reconnection_attempts,N},
+%%                    {reconnection_interval,Millisec},
+%%                    {keep_alive,Bool}]}.
+%%

Millisec = integer(), N = integer()

+%%

Enter the telnet_settings term in a configuration +%% file included in the test and ct_telnet will retrieve the information +%% automatically. Note that `keep_alive' may be specified per connection if +%% required. See `unix_telnet' for details.

%% -%%% === Logging example 1 === -%%% -%%% The following `ct_hooks' statement will cause raw printing of -%%% telnet traffic to separate logs for the connections named -%%% `server1' and `server2'. Any other connections will be logged -%%% to default telnet log. -%%% -%%% ``` -%%% suite() -> -%%% [{ct_hooks, [{cth_conn_log, [{ct_telnet,[{log_type,raw}}, -%%% {hosts,[server1,server2]}]} -%%% ]}]}]. -%%%''' -%%% -%%% === Logging example 2 === -%%% -%%% The following configuration file will cause raw logging of all -%%% telnet traffic into one single text file. -%%% -%%% ``` -%%% {ct_conn_log,[{ct_telnet,[{log_type,raw}]}]}. -%%% ''' -%%% -%%% The `ct_hooks' statement must look like this: -%%% -%%% ``` -%%% suite() -> -%%% [{ct_hooks, [{cth_conn_log, []}]}]. -%%% ''' -%%% -%%% The same `ct_hooks' statement without the configuration file would -%%% cause HTML logging of all telnet connections into the test case -%%% HTML log. -%%% -%%% Note that if the `cth_conn_log' hook is not added, telnet -%%% traffic is still logged in the test case log files (on the legacy -%%% `ct_telnet' format). - +%% == Logging == +%% +%% `ct_telnet' can be configured to uses the `error_logger' for logging telnet +%% traffic. A special purpose error handler is implemented in +%% `ct_conn_log_h'. To use this error handler, add the `cth_conn_log' +%% hook in your test suite, e.g: +%% +%% +%% ``` +%% suite() -> +%% [{ct_hooks, [{cth_conn_log, [{conn_mod(),hook_options()}]}]}]. +%%''' +%% +%% `conn_mod()' is the name of the common_test module implementing +%% the connection protocol, i.e. `ct_telnet'. +%% +%% The hook option `log_type' specifies the type of logging: +%% +%%
+%%
`raw'
+%%
The sent and received telnet data is logged to a separate +%% text file as is, without any formatting. A link to the file is +%% added to the test case HTML log.
+%% +%%
`html (default)'
+%%
The sent and received telnet traffic is pretty printed +%% directly in the test case HTML log.
+%% +%%
`silent'
+%%
Telnet traffic is not logged.
+%%
+%% +%% By default, all telnet traffic is logged in one single log +%% file. However, it is possible to have different connections logged +%% in separate files. To do this, use the hook option `hosts' and +%% list the names of the servers/connections that will be used in the +%% suite. Note that the connections must be named for this to work +%% (see the `open' function below). +%% +%% The `hosts' option has no effect if `log_type' is set to `html' or +%% `silent'. +%% +%% The hook options can also be specified in a configuration file with +%% the configuration variable `ct_conn_log': +%% +%% ``` +%% {ct_conn_log,[{conn_mod(),hook_options()}]}. +%% ''' +%% +%% For example: +%% +%% ``` +%% {ct_conn_log,[{ct_telnet,[{log_type,raw}, +%% {hosts,[key_or_name()]}]}]} +%% ''' +%% +%% Note that hook options specified in a configuration file +%% will overwrite any hardcoded hook options in the test suite. +%% +%% === Logging example 1 === +%% +%% The following `ct_hooks' statement will cause raw printing of +%% telnet traffic to separate logs for the connections named +%% `server1' and `server2'. Any other connections will be logged +%% to default telnet log. +%% +%% ``` +%% suite() -> +%% [{ct_hooks, [{cth_conn_log, [{ct_telnet,[{log_type,raw}}, +%% {hosts,[server1,server2]}]} +%% ]}]}]. +%%''' +%% +%% === Logging example 2 === +%% +%% The following configuration file will cause raw logging of all +%% telnet traffic into one single text file. +%% +%% ``` +%% {ct_conn_log,[{ct_telnet,[{log_type,raw}]}]}. +%% ''' +%% +%% The `ct_hooks' statement must look like this: +%% +%% ``` +%% suite() -> +%% [{ct_hooks, [{cth_conn_log, []}]}]. +%% ''' +%% +%% The same `ct_hooks' statement without the configuration file would +%% cause HTML logging of all telnet connections into the test case +%% HTML log. +%% +%% Note that if the `cth_conn_log' hook is not added, telnet +%% traffic is still logged in the test case HTML log file (on the legacy +%% `ct_telnet' format). +%% @end -%%% @type connection_type() = telnet | ts1 | ts2 +%% @type connection_type() = telnet | ts1 | ts2 -%%% @type connection() = handle() | -%%% {ct:target_name(),connection_type()} | ct:target_name() +%% @type connection() = handle() | +%% {ct:target_name(),connection_type()} | ct:target_name() -%%% @type handle() = ct_gen_conn:handle(). Handle for a -%%% specific telnet connection. +%% @type handle() = ct_gen_conn:handle(). Handle for a +%% specific telnet connection. -%%% @type prompt_regexp() = string(). A regular expression which -%%% matches all possible prompts for a specific type of target. The -%%% regexp must not have any groups i.e. when matching, re:run/3 shall -%%% return a list with one single element. -%%% -%%% @see unix_telnet +%% @type prompt_regexp() = string(). A regular expression which +%% matches all possible prompts for a specific type of target. The +%% regexp must not have any groups i.e. when matching, re:run/3 shall +%% return a list with one single element. +%% +%% @see unix_telnet -module(ct_telnet). -- cgit v1.2.3