aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorHenrik Nord <[email protected]>2014-12-02 10:39:06 +0100
committerHenrik Nord <[email protected]>2014-12-02 10:39:06 +0100
commitbf86161c2366936457139293fe7c326dd830b62b (patch)
tree0b4c914d3964b53f80ccd77d2bae9b8236600c54
parent8feba1dc8de811859d61451fea85b21332ac6e43 (diff)
parent611394791acbe7ae98417b9115aeeaa7046e78a2 (diff)
downloadotp-bf86161c2366936457139293fe7c326dd830b62b.tar.gz
otp-bf86161c2366936457139293fe7c326dd830b62b.tar.bz2
otp-bf86161c2366936457139293fe7c326dd830b62b.zip
Merge branch 'siri/ct_telnet/unstable-tests/OTP-12329' into maint
* siri/ct_telnet/unstable-tests/OTP-12329: [ct_telnet] Fix test case 'server_speaks' [ct_telnet] Improve debug printouts and logging [ct_telnet] Add timestamp to telnet_server debug printout [ct_telnet] Extend timeout in test from 1 to 2 sek [ct_telnet] Don't send extra newline after password
-rw-r--r--lib/common_test/src/ct_telnet_client.erl44
-rw-r--r--lib/common_test/src/unix_telnet.erl4
-rw-r--r--lib/common_test/test/ct_telnet_SUITE_data/ct_telnet_own_server_SUITE.erl44
-rw-r--r--lib/common_test/test/telnet_server.erl12
4 files changed, 72 insertions, 32 deletions
diff --git a/lib/common_test/src/ct_telnet_client.erl b/lib/common_test/src/ct_telnet_client.erl
index 3ae373e433..36d33522a3 100644
--- a/lib/common_test/src/ct_telnet_client.erl
+++ b/lib/common_test/src/ct_telnet_client.erl
@@ -250,7 +250,13 @@ wait(false, _) -> infinity.
send(Data, Sock, ConnName) ->
case Data of
[?IAC|_] = Cmd ->
- cmd_dbg(Cmd);
+ cmd_dbg("Sending",Cmd),
+ try io_lib:format("[~w] ~w", [?MODULE,Data]) of
+ Str ->
+ ct_telnet:log(ConnName, general_io, Str, [])
+ catch
+ _:_ -> ok
+ end;
_ ->
dbg("Sending: ~tp\n", [Data]),
try io_lib:format("[~w] ~ts", [?MODULE,Data]) of
@@ -271,8 +277,7 @@ check_msg(Sock, [?IAC,?IAC | T], Acc) ->
check_msg(Sock, [?IAC | Cs], Acc) ->
case get_cmd(Cs) of
{Cmd,Cs1} ->
- dbg("Got ", []),
- cmd_dbg(Cmd),
+ cmd_dbg("Got",Cmd),
respond_cmd(Cmd, Sock),
check_msg(Sock, Cs1, Acc);
error ->
@@ -291,12 +296,12 @@ check_msg(_Sock, [], Acc) ->
respond_cmd([?WILL,?ECHO], Sock) ->
R = [?IAC,?DO,?ECHO],
- cmd_dbg(R),
+ cmd_dbg("Responding",R),
gen_tcp:send(Sock, R);
respond_cmd([?DO,?ECHO], Sock) ->
R = [?IAC,?WILL,?ECHO],
- cmd_dbg(R),
+ cmd_dbg("Responding",R),
gen_tcp:send(Sock, R);
%% Answers from server
@@ -316,12 +321,12 @@ respond_cmd([?WONT | _Opt], _Sock) -> % server ack?
respond_cmd([?WILL,Opt], Sock) ->
R = [?IAC,?DONT,Opt],
- cmd_dbg(R),
+ cmd_dbg("Responding",R),
gen_tcp:send(Sock, R);
respond_cmd([?DO | Opt], Sock) ->
R = [?IAC,?WONT | Opt],
- cmd_dbg(R),
+ cmd_dbg("Responding",R),
gen_tcp:send(Sock, R);
%% Commands without options (which we ignore)
@@ -357,13 +362,14 @@ get_subcmd([Opt | Rest], Acc) ->
get_subcmd(Rest, [Opt | Acc]).
-ifdef(debug).
-dbg(_Str,_Args) ->
- io:format(_Str,_Args).
+dbg(Str,Args) ->
+ TS = timestamp(),
+ io:format("[~p ct_telnet_client, ~s]\n" ++ Str,[self(),TS|Args]).
-cmd_dbg(_Cmd) ->
- case _Cmd of
+cmd_dbg(Prefix,Cmd) ->
+ case Cmd of
[?IAC|Cmd1] ->
- cmd_dbg(Cmd1);
+ cmd_dbg(Prefix,Cmd1);
[Ctrl|Opts] ->
CtrlStr =
case Ctrl of
@@ -379,15 +385,23 @@ cmd_dbg(_Cmd) ->
[Opt] -> Opt;
_ -> Opts
end,
- io:format("~ts(~w): ~w\n", [CtrlStr,Ctrl,Opts1]);
+ dbg("~ts: ~ts(~w): ~w\n", [Prefix,CtrlStr,Ctrl,Opts1]);
Any ->
- io:format("Unexpected in cmd_dbg:~n~w~n",[Any])
+ dbg("Unexpected in cmd_dbg:~n~w~n",[Any])
end.
+timestamp() ->
+ {MS,S,US} = now(),
+ {{Year,Month,Day}, {Hour,Min,Sec}} =
+ calendar:now_to_local_time({MS,S,US}),
+ MilliSec = trunc(US/1000),
+ lists:flatten(io_lib:format("~4.10.0B-~2.10.0B-~2.10.0B "
+ "~2.10.0B:~2.10.0B:~2.10.0B.~3.10.0B",
+ [Year,Month,Day,Hour,Min,Sec,MilliSec])).
-else.
dbg(_Str,_Args) ->
ok.
-cmd_dbg(_Cmd) ->
+cmd_dbg(_Prefix,_Cmd) ->
ok.
-endif.
diff --git a/lib/common_test/src/unix_telnet.erl b/lib/common_test/src/unix_telnet.erl
index 10666b979d..09b6fd1510 100644
--- a/lib/common_test/src/unix_telnet.erl
+++ b/lib/common_test/src/unix_telnet.erl
@@ -1,7 +1,7 @@
%%
%% %CopyrightBegin%
%%
-%% Copyright Ericsson AB 2004-2013. All Rights Reserved.
+%% Copyright Ericsson AB 2004-2014. All Rights Reserved.
%%
%% The contents of this file are subject to the Erlang Public License,
%% Version 1.1, (the "License"); you may not use this file except in
@@ -122,7 +122,7 @@ connect1(Name,Ip,Port,Timeout,KeepAlive,Username,Password) ->
ok = ct_telnet_client:send_data(Pid,Password),
Stars = lists:duplicate(length(Password),$*),
log(Name,send,"Password: ~s",[Stars]),
- ok = ct_telnet_client:send_data(Pid,""),
+% ok = ct_telnet_client:send_data(Pid,""),
case ct_telnet:silent_teln_expect(Name,Pid,[],
prompt,
?prx,[]) of
diff --git a/lib/common_test/test/ct_telnet_SUITE_data/ct_telnet_own_server_SUITE.erl b/lib/common_test/test/ct_telnet_SUITE_data/ct_telnet_own_server_SUITE.erl
index 9afe545b26..0ddb4e9b00 100644
--- a/lib/common_test/test/ct_telnet_SUITE_data/ct_telnet_own_server_SUITE.erl
+++ b/lib/common_test/test/ct_telnet_SUITE_data/ct_telnet_own_server_SUITE.erl
@@ -22,6 +22,8 @@
-define(DONT, 254).
-define(IAC, 255).
+-define(SHORT_TIME,2000).
+
%%--------------------------------------------------------------------
%% TEST SERVER CALLBACK FUNCTIONS
%%--------------------------------------------------------------------
@@ -115,7 +117,7 @@ expect_error_prompt(_) ->
expect_error_timeout1(_) ->
{ok, Handle} = ct_telnet:open(telnet_server_conn1),
ok = ct_telnet:send(Handle, "echo_no_prompt xxx"),
- {error,timeout} = ct_telnet:expect(Handle, ["xxx"], [{timeout,1000}]),
+ {error,timeout} = ct_telnet:expect(Handle, ["xxx"], [{timeout,?SHORT_TIME}]),
ok = ct_telnet:close(Handle),
ok.
@@ -178,16 +180,16 @@ ignore_prompt_timeout(_) ->
{ok, Handle} = ct_telnet:open(telnet_server_conn1),
ok = ct_telnet:send(Handle, "echo xxx"),
{error,timeout} = ct_telnet:expect(Handle, ["yyy"], [ignore_prompt,
- {timeout,1000}]),
+ {timeout,?SHORT_TIME}]),
ok = ct_telnet:send(Handle, "echo xxx"), % sends prompt and newline
{ok,["xxx"]} = ct_telnet:expect(Handle, ["xxx"], [ignore_prompt,
- {timeout,1000}]),
+ {timeout,?SHORT_TIME}]),
ok = ct_telnet:send(Handle, "echo_no_prompt xxx\n"), % no prompt, but newline
{ok,["xxx"]} = ct_telnet:expect(Handle, ["xxx"], [ignore_prompt,
- {timeout,1000}]),
+ {timeout,?SHORT_TIME}]),
ok = ct_telnet:send(Handle, "echo_no_prompt xxx"), % no prompt, no newline
{error,timeout} = ct_telnet:expect(Handle, ["xxx"], [ignore_prompt,
- {timeout,1000}]),
+ {timeout,?SHORT_TIME}]),
ok = ct_telnet:close(Handle),
ok.
@@ -233,7 +235,7 @@ no_prompt_check_timeout(_) ->
{ok, Handle} = ct_telnet:open(telnet_server_conn1),
ok = ct_telnet:send(Handle, "echo xxx"),
{error,timeout} = ct_telnet:expect(Handle, ["yyy"], [no_prompt_check,
- {timeout,1000}]),
+ {timeout,?SHORT_TIME}]),
ok = ct_telnet:close(Handle),
ok.
@@ -274,17 +276,31 @@ large_string(_) ->
%% The server says things. Manually check that it gets printed correctly
%% in the general IO log.
+%%
+%% In this test case we simulate data sent spontaneously from the
+%% server. We use ct_telnet_client:send_data instead of ct_telnet:send
+%% to avoid flushing of buffers in the client, and we use
+%% echo_no_prompt since the server would normally not send a prompt in
+%% this case.
server_speaks(_) ->
{ok, Handle} = ct_telnet:open(telnet_server_conn1),
- ok = ct_telnet:send(Handle, "echo_no_prompt This is the first message\r\n"),
- ok = ct_telnet:send(Handle, "echo_no_prompt This is the second message\r\n"),
- %% let ct_telnet_client get an idle timeout
+
+ Backdoor = ct_gen_conn:get_conn_pid(Handle),
+ ok = ct_telnet_client:send_data(Backdoor,
+ "echo_no_prompt This is the first message"),
+ ok = ct_telnet_client:send_data(Backdoor,
+ "echo_no_prompt This is the second message"),
+ %% Let ct_telnet_client get an idle timeout. This should print the
+ %% two messages to the log. Note that the buffers are not flushed here!
timer:sleep(15000),
- ok = ct_telnet:send(Handle, "echo_no_prompt This is the third message\r\n"),
- {ok,_} = ct_telnet:expect(Handle, ["the"], [no_prompt_check]),
+ ok = ct_telnet_client:send_data(Backdoor,
+ "echo_no_prompt This is the third message"),
+ {ok,_} = ct_telnet:expect(Handle, ["first.*second.*third"],
+ [no_prompt_check, sequence]),
{error,timeout} = ct_telnet:expect(Handle, ["the"], [no_prompt_check,
- {timeout,1000}]),
- ok = ct_telnet:send(Handle, "echo_no_prompt This is the fourth message\r\n"),
+ {timeout,?SHORT_TIME}]),
+ ok = ct_telnet_client:send_data(Backdoor,
+ "echo_no_prompt This is the fourth message"),
%% give the server time to respond
timer:sleep(2000),
%% closing the connection should print last message in log
@@ -299,7 +315,7 @@ server_disconnects(_) ->
%% wait until the get_data operation (triggered by send/2) times out
%% before sending the msg
timer:sleep(500),
- ok = ct_telnet:send(Handle, "echo_no_prompt This is the message\r\n"),
+ ok = ct_telnet:send(Handle, "echo_no_prompt This is the message"),
%% when the server closes the connection, the last message should be
%% printed in the log
timer:sleep(3000),
diff --git a/lib/common_test/test/telnet_server.erl b/lib/common_test/test/telnet_server.erl
index 0a23a66324..d25ee62d38 100644
--- a/lib/common_test/test/telnet_server.erl
+++ b/lib/common_test/test/telnet_server.erl
@@ -310,4 +310,14 @@ get_line([],_) ->
dbg(_F) ->
dbg(_F,[]).
dbg(_F,_A) ->
- io:format("[telnet_server] " ++ _F,_A).
+ TS = timestamp(),
+ io:format("[telnet_server, ~s]\n" ++ _F,[TS|_A]).
+
+timestamp() ->
+ {MS,S,US} = now(),
+ {{Year,Month,Day}, {Hour,Min,Sec}} =
+ calendar:now_to_local_time({MS,S,US}),
+ MilliSec = trunc(US/1000),
+ lists:flatten(io_lib:format("~4.10.0B-~2.10.0B-~2.10.0B "
+ "~2.10.0B:~2.10.0B:~2.10.0B.~3.10.0B",
+ [Year,Month,Day,Hour,Min,Sec,MilliSec])).