Merge remote branch 'origin/peppe/common_test/telnet_logging_final'

* origin/peppe/common_test/telnet_logging_final:
  Add test cases and fix some problems with logging and with the telnet client
  Get ct_telnet_client to print all data from server to log
  Change telnet logging behaviour

OTP-11690

8 files changed, 301 insertions, 138 deletions

diff --git a/lib/common_test/src/ct_gen_conn.erl b/lib/common_test/src/ct_gen_conn.erl
index 078d6b1a44..239f5b5f25 100644
--- a/lib/common_test/src/ct_gen_conn.erl
+++ b/lib/common_test/src/ct_gen_conn.erl
@@ -344,7 +344,7 @@ loop(Opts) ->
 			    link(NewPid),
 			    put(conn_pid,NewPid),
 			    loop(Opts#gen_opts{conn_pid=NewPid,
-					       cb_state=NewState});
+					       cb_state=NewState});			
 			Error ->
 			    ct_util:unregister_connection(self()),
 			    log("Reconnect failed. Giving up!",
diff --git a/lib/common_test/src/ct_telnet.erl b/lib/common_test/src/ct_telnet.erl
index b4d82a53cf..8c3ce03732 100644
--- a/lib/common_test/src/ct_telnet.erl
+++ b/lib/common_test/src/ct_telnet.erl
@@ -281,8 +281,16 @@ open(KeyOrName,ConnType,TargetMod,Extra) ->
 		end,
 	    log(undefined,open,"Connecting to ~p(~p)",
 		[KeyOrName,Addr1]),
-	    ct_gen_conn:start(KeyOrName,full_addr(Addr1,ConnType),
-			      {TargetMod,KeepAlive,Extra},?MODULE)
+	    Reconnect =
+		case ct:get_config({telnet_settings,reconnection_attempts}) of
+		    0 -> false;
+		    _ -> true
+		end,
+	    ct_gen_conn:start(full_addr(Addr1,ConnType),
+			      {TargetMod,KeepAlive,Extra},
+			      ?MODULE, [{name,KeyOrName},
+					{reconnect,Reconnect},
+					{old,true}])
     end.
 
 %%%-----------------------------------------------------------------
@@ -601,11 +609,9 @@ handle_msg({cmd,Cmd,Timeout},State) ->
     end_gen_log(),
     {Return,State#state{buffer=NewBuffer,prompt=Prompt}};
 handle_msg({send,Cmd},State) ->
-    log(State,send,"Cmd: ~p",[Cmd]),
-
+    log(State,send,"Sending: ~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.name,
@@ -783,66 +789,61 @@ log(#state{name=Name,teln_pid=TelnPid,host=Host,port=Port},
 	       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;
-	_ 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)
+
+    if Action == general_io ->
+	    case ct_util:get_testdata({cth_conn_log,?MODULE}) of
+		HookMode when HookMode /= undefined, HookMode /= silent,
+			      Silent /= true ->
+		    error_logger:info_report(#conn_log{header=false,
+						       client=self(),
+						       conn_pid=TelnPid,
+						       address={Host,Port},
+						       name=Name1,
+						       action=Action,
+						       module=?MODULE},
+					     {String,Args});
+		_ -> %% hook inactive or silence requested
+		    ok
 	    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
+
+       true ->	    
+	    if Action == open; Action == close; Action == reconnect;
+	       Action == info; Action == error ->
 		    ct_gen_conn:log(heading(Action,Name1),String,Args);
-		false ->
-		    ct_gen_conn:cont_log(String,Args)
+
+	       ForcePrint == false ->
+		    case ct_util:is_silenced(telnet) of
+			true  ->
+			    ok;
+			false ->
+			    ct_gen_conn:cont_log(String,Args)
+		    end;
+	       
+	       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
     end.
 
 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
+    %% check if output is suppressed
+    case ct_util:is_silenced(telnet) of
+	true  -> ok;
+	false -> ct_gen_conn:start_log(Heading)
     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
+    %% check if output is suppressed
+    case ct_util:is_silenced(telnet) of
+	true  -> ok;
+	false -> ct_gen_conn:end_log()
     end.
 
 %%% @hidden
@@ -1027,19 +1028,25 @@ teln_expect1(Name,Pid,Data,Pattern,Acc,EO) ->
 	NotFinished ->
 	    %% Get more data
 	    Fun = fun() -> get_data1(EO#eo.teln_pid) end,
-	    case ct_gen_conn:do_within_time(Fun, EO#eo.timeout) of
-		{error,Reason} -> 
+	    case timer:tc(ct_gen_conn, do_within_time, [Fun, EO#eo.timeout]) of
+		{_,{error,Reason}} -> 
 		    %% A timeout will occur when the telnet connection
 		    %% is idle for EO#eo.timeout milliseconds.
 		    {error,Reason};
-		{ok,Data1} ->
-		    case NotFinished of
-			{nomatch,Rest} ->
-			    %% One expect
-			    teln_expect1(Name,Pid,Rest++Data1,Pattern,[],EO);
-			{continue,Patterns1,Acc1,Rest} ->
-			    %% Sequence
-			    teln_expect1(Name,Pid,Rest++Data1,Patterns1,Acc1,EO)
+		{Elapsed,{ok,Data1}} ->
+		    TVal = trunc(EO#eo.timeout - (Elapsed/1000)),
+		    if TVal =< 0 ->
+			    {error,timeout};
+		       true ->
+			    EO1 = EO#eo{timeout = TVal},
+			    case NotFinished of
+				{nomatch,Rest} ->
+				    %% One expect
+				    teln_expect1(Name,Pid,Rest++Data1,Pattern,[],EO1);
+				{continue,Patterns1,Acc1,Rest} ->
+				    %% Sequence
+				    teln_expect1(Name,Pid,Rest++Data1,Patterns1,Acc1,EO1)
+			    end
 		    end
 	    end
     end.
diff --git a/lib/common_test/src/ct_telnet_client.erl b/lib/common_test/src/ct_telnet_client.erl
index 2cbcba9c77..ce30dcb74b 100644
--- a/lib/common_test/src/ct_telnet_client.erl
+++ b/lib/common_test/src/ct_telnet_client.erl
@@ -32,7 +32,9 @@
 
 -module(ct_telnet_client).
 
--export([open/1, open/2, open/3, open/4, close/1]).
+%% -define(debug, true).
+
+-export([open/2, open/3, open/4, open/5, close/1]).
 -export([send_data/2, get_data/1]).
 
 -define(TELNET_PORT, 23).
@@ -64,20 +66,23 @@
 -define(TERMINAL_TYPE,     24).  
 -define(WINDOW_SIZE,       31).
 
--record(state,{get_data, keep_alive=true}).
+-record(state,{conn_name, get_data, keep_alive=true, log_pos=1}).
 
-open(Server) ->
-    open(Server, ?TELNET_PORT, ?OPEN_TIMEOUT, true).
+open(Server, ConnName) ->
+    open(Server, ?TELNET_PORT, ?OPEN_TIMEOUT, true, ConnName).
 
-open(Server, Port) ->
-    open(Server, Port, ?OPEN_TIMEOUT, true).
+open(Server, Port, ConnName) ->
+    open(Server, Port, ?OPEN_TIMEOUT, true, ConnName).
 
-open(Server, Port, Timeout) ->
-    open(Server, Port, Timeout, true).
+open(Server, Port, Timeout, ConnName) ->
+    open(Server, Port, Timeout, true, ConnName).
 
-open(Server, Port, Timeout, KeepAlive) ->
+open(Server, Port, Timeout, KeepAlive, ConnName) ->
     Self = self(),
-    Pid = spawn(fun() -> init(Self, Server, Port, Timeout, KeepAlive) end),
+    Pid = spawn(fun() ->
+			init(Self, Server, Port, Timeout,
+			     KeepAlive, ConnName)
+		end),
     receive 
 	{open,Pid} ->
 	    {ok,Pid};
@@ -86,29 +91,34 @@ open(Server, Port, Timeout, KeepAlive) ->
     end.
 
 close(Pid) ->
-    Pid ! close.
+    Pid ! {close,self()},
+    receive closed -> ok 
+    after 5000 -> ok
+    end.	    
 
 send_data(Pid, Data) ->
     Pid ! {send_data, Data++"\n"},
     ok.
 
 get_data(Pid) ->
-    Pid ! {get_data, self()},
+    Pid ! {get_data,self()},
     receive 
 	{data,Data} ->
-	    {ok, Data}
+	    {ok,Data}
     end.
 
 
 %%%-----------------------------------------------------------------
 %%% Internal functions
-init(Parent, Server, Port, Timeout, KeepAlive) ->
+init(Parent, Server, Port, Timeout, KeepAlive, ConnName) ->
     case gen_tcp:connect(Server, Port, [list,{packet,0}], Timeout) of
 	{ok,Sock} ->
-	    dbg("Connected to: ~p (port: ~w, keep_alive: ~w)\n", [Server,Port,KeepAlive]),
-	    send([?IAC,?DO,?SUPPRESS_GO_AHEAD], Sock),	      
+	    dbg("~p connected to: ~p (port: ~w, keep_alive: ~w)\n",
+		[ConnName,Server,Port,KeepAlive]),
+	    send([?IAC,?DO,?SUPPRESS_GO_AHEAD], Sock, ConnName),	      
 	    Parent ! {open,self()},
-	    loop(#state{get_data=10, keep_alive=KeepAlive}, Sock, []),
+	    loop(#state{conn_name=ConnName, get_data=10, keep_alive=KeepAlive},
+		 Sock, []),
 	    gen_tcp:close(Sock);
         Error ->
 	    Parent ! {Error,self()}
@@ -118,6 +128,13 @@ loop(State, Sock, Acc) ->
     receive
 	{tcp_closed,_} ->
 	    dbg("Connection closed\n", []),
+	    Data = lists:reverse(lists:append(Acc)),
+	    dbg("Printing queued messages: ~tp",[Data]),
+	    ct_telnet:log(State#state.conn_name,
+			  general_io, "~ts",
+			  [lists:sublist(Data,
+					 State#state.log_pos,
+					 length(Data))]),
 	    receive
 		{get_data,Pid} ->
 		    Pid ! closed
@@ -125,11 +142,11 @@ loop(State, Sock, Acc) ->
 		    ok
 	    end;
 	{tcp,_,Msg0} ->
-	    dbg("tcp msg: ~p~n",[Msg0]),
+	    dbg("tcp msg: ~tp~n",[Msg0]),
 	    Msg = check_msg(Sock,Msg0,[]),
 	    loop(State, Sock, [Msg | Acc]);
 	{send_data,Data} ->
-	    send(Data, Sock),
+	    send(Data, Sock, State#state.conn_name),
 	    loop(State, Sock, Acc);
 	{get_data,Pid} ->
 	    NewState = 
@@ -144,54 +161,100 @@ loop(State, Sock, Acc) ->
 			end;
 		    _ ->
 			Data = lists:reverse(lists:append(Acc)),
-			dbg("get_data ~p\n",[Data]),
+			Len = length(Data),
+			dbg("get_data ~tp\n",[Data]),
+			ct_telnet:log(State#state.conn_name,
+				      general_io, "~ts",
+				      [lists:sublist(Data,
+						     State#state.log_pos,
+						     Len)]),
 			Pid ! {data,Data},
-			State
+			State#state{log_pos = 1}
 		end,
 	    loop(NewState, Sock, []);
 	{get_data_delayed,Pid} ->
 	    NewState =
 		case State of
 		    #state{keep_alive = true, get_data = 0} ->
-			if Acc == [] -> send([?IAC,?NOP], Sock);
+			if Acc == [] -> send([?IAC,?NOP], Sock, 
+					     State#state.conn_name);
 			   true -> ok
 			end,
 			State#state{get_data=10};
 		    _ ->
 			State
 		end,
-	    NewAcc = 
+	    {NewAcc,Pos} = 
 		case erlang:is_process_alive(Pid) of
-		    true ->
+		    true when Acc /= [] ->
 			Data = lists:reverse(lists:append(Acc)),
-			dbg("get_data_delayed ~p\n",[Data]),
+			Len = length(Data),
+			dbg("get_data_delayed ~tp\n",[Data]),
+			ct_telnet:log(State#state.conn_name,
+				      general_io, "~ts",
+				      [lists:sublist(Data,
+						     State#state.log_pos,
+						     Len)]),
 			Pid ! {data,Data},
-			[];
+			{[],1};
+		    true when Acc == [] ->
+			dbg("get_data_delayed nodata\n",[]),
+			Pid ! {data,[]},
+			{[],1};
 		    false ->
-			Acc
+			{Acc,NewState#state.log_pos}
 		end,
-	    loop(NewState, Sock, NewAcc);			       
-	close ->
+	    loop(NewState#state{log_pos=Pos}, Sock, NewAcc);			       
+	{close,Pid} ->
 	    dbg("Closing connection\n", []),
+	    if Acc == [] ->
+		    ok;
+	       true ->
+		    Data = lists:reverse(lists:append(Acc)),
+		    dbg("Printing queued messages: ~tp",[Data]),
+		    ct_telnet:log(State#state.conn_name,
+				  general_io, "~ts",
+				  [lists:sublist(Data,
+						 State#state.log_pos,
+						 length(Data))])
+	    end,
 	    gen_tcp:close(Sock),
-	    ok
+	    Pid ! closed
     after wait(State#state.keep_alive,?IDLE_TIMEOUT) ->
-	    if 
-		Acc == [] -> send([?IAC,?NOP], Sock);
-		true -> ok
-	    end,
-	    loop(State, Sock, Acc)
+	    Data = lists:reverse(lists:append(Acc)),
+	    case Data of
+		[] ->
+		    send([?IAC,?NOP], Sock, State#state.conn_name),
+		    loop(State, Sock, Acc);
+		_ when State#state.log_pos == length(Data)+1 ->
+		    loop(State, Sock, Acc);
+		_ ->
+		    dbg("Idle timeout, printing ~tp\n",[Data]),
+		    Len = length(Data),
+		    ct_telnet:log(State#state.conn_name,
+				  general_io, "~ts",
+				  [lists:sublist(Data,
+						 State#state.log_pos,
+						 Len)]),
+		    loop(State#state{log_pos = Len+1}, Sock, Acc)
+	    end
     end.
 
 wait(true, Time) -> Time;
 wait(false, _) -> infinity.   
 
-send(Data, Sock) ->
+send(Data, Sock, ConnName) ->
     case Data of
 	[?IAC|_] = Cmd ->
 	    cmd_dbg(Cmd);
 	_ ->
-	    dbg("Sending: ~p\n", [Data])
+	    dbg("Sending: ~tp\n", [Data]),
+	    try io_lib:format("[~w] ~ts", [?MODULE,Data]) of
+		Str ->
+		    ct_telnet:log(ConnName, general_io, Str, [])
+	    catch
+		_:_ -> ok
+	    end
     end,
     gen_tcp:send(Sock, Data),
     ok.
diff --git a/lib/common_test/src/unix_telnet.erl b/lib/common_test/src/unix_telnet.erl
index e049c3bf39..b05386a5ab 100644
--- a/lib/common_test/src/unix_telnet.erl
+++ b/lib/common_test/src/unix_telnet.erl
@@ -109,7 +109,7 @@ connect(ConnName,Ip,Port,Timeout,KeepAlive,Extra) ->
 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
+	case ct_telnet_client:open(Ip,Port,Timeout,KeepAlive,Name) of
 	    {ok,Pid} ->
 		case ct_telnet:silent_teln_expect(Name,Pid,[],
 						  [prompt],?prx,[]) of
@@ -143,13 +143,13 @@ connect1(Name,Ip,Port,Timeout,KeepAlive,Username,Password) ->
 		    {ok,[{prompt,_OtherPrompt1},{prompt,_OtherPrompt2}],_} ->
 			{ok,Pid};
 		    Error ->
-			log(Name,error,
+			log(Name,conn_error,
 			    "Did not get expected prompt from ~p:~p\n~p\n",
 			    [Ip,Port,Error]),
 			{error,Error}
 		end;
 	    Error ->
-		log(Name,error,
+		log(Name,conn_error,
 		    "Could not open telnet connection to ~p:~p\n~p\n",
 		    [Ip,Port,Error]),
 		Error
diff --git a/lib/common_test/test/ct_telnet_SUITE.erl b/lib/common_test/test/ct_telnet_SUITE.erl
index acce4eca14..f5cff76fd1 100644
--- a/lib/common_test/test/ct_telnet_SUITE.erl
+++ b/lib/common_test/test/ct_telnet_SUITE.erl
@@ -72,19 +72,32 @@ init_per_suite(Config) ->
 end_per_suite(Config) ->
     ct_test_support:end_per_suite(Config).
 
-init_per_testcase(TestCase, Config) when TestCase=/=unix_telnet->
+init_per_testcase(TestCase, Config) when TestCase /= unix_telnet ->
+    ct:pal("Testcase ~p starting!", [TestCase]),
     TS = telnet_server:start([{port,?erl_telnet_server_port},
 			      {users,[{?erl_telnet_server_user,
 				       ?erl_telnet_server_pwd}]}]),
     ct_test_support:init_per_testcase(TestCase, [{telnet_server,TS}|Config]);
 init_per_testcase(TestCase, Config) ->
-    ct_test_support:init_per_testcase(TestCase, Config).
-
+    ct:pal("Testcase ~p starting. Checking connection to telnet server...",
+	   [TestCase]),
+    ct:require(testconn, {unix,[telnet]}),
+    case {os:type(),ct_telnet:open(testconn)} of
+	{_,{ok,Handle}} ->
+	    ok = ct_telnet:close(Handle),
+	    ct:pal("Connection ok, starting tests!", []),
+	    ct_test_support:init_per_testcase(TestCase, Config);
+	{{unix,_},{error,Reason}} ->
+	    ct:fail("No connection to telnet server! Reason: ~tp", [Reason]);
+	{_,{error,Reason}} ->
+	    {skip,{no_access_to_telnet_server,Reason}}
+    end.		
+
+end_per_testcase(TestCase, Config) when TestCase /= unix_telnet ->
+    ct:pal("Stopping the telnet_server now!", []),
+    telnet_server:stop(?config(telnet_server,Config)),
+    ct_test_support:end_per_testcase(TestCase, Config);
 end_per_testcase(TestCase, Config) ->
-    case ?config(telnet_server,Config) of
-	undefined -> ok;
-	TS -> telnet_server:stop(TS)
-    end,
     ct_test_support:end_per_testcase(TestCase, Config).
 
 
@@ -179,7 +192,12 @@ telnet_config(_, LogType) ->
 	    {port, ?erl_telnet_server_port},
 	    {username,?erl_telnet_server_user},
 	    {password,?erl_telnet_server_pwd},
-	    {keep_alive,true}]} |
+	    {keep_alive,true}]},
+     {telnet_settings, [{connect_timeout,10000},
+			{command_timeout,10000},
+			{reconnection_attempts,0},
+			{reconnection_interval,0},
+			{keep_alive,true}]} |
      if LogType == legacy -> 
 	     [{ct_conn_log,[]}];
 	true ->
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 8d142e85a8..394d64c2ed 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
@@ -28,7 +28,9 @@ all() ->
      ignore_prompt,
      ignore_prompt_repeat,
      ignore_prompt_sequence,
-     ignore_prompt_timeout].
+     ignore_prompt_timeout,
+     server_speaks,
+     server_disconnects].
 
 groups() ->
     [].
@@ -188,3 +190,37 @@ no_prompt_check_timeout(_) ->
 							 {timeout,1000}]),
     ok = ct_telnet:close(Handle),
     ok.
+
+%% The server says things. Manually check that it gets printed correctly
+%% in the general IO log.
+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
+    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]),
+    {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"),
+    %% give the server time to respond
+    timer:sleep(2000),
+    %% closing the connection should print last message in log
+    ok = ct_telnet:close(Handle),
+    ok.  
+
+%% Let the server close the connection. Make sure buffered data gets printed
+%% to the general IO log.
+server_disconnects(_) ->
+    {ok, Handle} = ct_telnet:open(telnet_server_conn1),
+    ok = ct_telnet:send(Handle, "disconnect_after 1500"),
+    %% 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"),
+    %% when the server closes the connection, the last message should be
+    %% printed in the log
+    timer:sleep(3000),
+    _ = ct_telnet:close(Handle),
+    ok.
diff --git a/lib/common_test/test/telnet_server.erl b/lib/common_test/test/telnet_server.erl
index 1760100d8e..3b0c3cbcb5 100644
--- a/lib/common_test/test/telnet_server.erl
+++ b/lib/common_test/test/telnet_server.erl
@@ -51,32 +51,51 @@ stop(Pid) ->
 init(Opts) ->
     Port = proplists:get_value(port,Opts),
     Users = proplists:get_value(users,Opts,[]),
-    {ok, LSock} = gen_tcp:listen(Port, [list, {packet, 0}, 
-                                        {active, true}]),
+    {ok, LSock} = listen(5, Port, [list, {packet, 0}, 
+				   {active, true},
+				   {reuseaddr,true}]),
     State = #state{listen=LSock,users=Users},
     accept(State),
-    ok = gen_tcp:close(LSock).
+    ok = gen_tcp:close(LSock),
+    dbg("telnet_server closed the listen socket ~p\n", [LSock]),
+    timer:sleep(1000),
+    ok.
+
+listen(0, _Port, _Opts) ->
+    {error,eaddrinuse};
+listen(Retries, Port, Opts) ->
+    case gen_tcp:listen(Port, Opts) of
+	{error,eaddrinuse} ->
+	    dbg("Listen port not released, trying again..."),
+	    timer:sleep(5000),
+	    listen(Retries-1, Port, Opts);
+	Ok = {ok,_LSock} ->
+	    Ok;
+	Error ->
+	    exit(Error)
+    end.
 
 accept(#state{listen=LSock}=State) ->
     Server = self(),
     Acceptor = spawn_link(fun() -> do_accept(LSock,Server) end),
     receive 
 	{Acceptor,Sock} when is_port(Sock) ->
+	    dbg("Connected to client on socket ~p\n", [Sock]),
 	    case init_client(State#state{client=Sock}) of
 		stopped ->
-		    io:format("[telnet_server] telnet_server stopped\n"),
+		    dbg("telnet_server stopped\n"),
 		    ok;
 		R ->
-		    io:format("[telnet_server] connection to client" 
-			      "closed with reason ~p~n",[R]),
+		    dbg("Connection to client " 
+			"closed with reason ~p~n",[R]),
 		    accept(State)
 	    end;
 	{Acceptor,closed} ->
-	    io:format("[telnet_server] listen socket closed unexpectedly, "
-		      "terminating telnet_server\n"),
+	    dbg("Listen socket closed unexpectedly, "
+		"terminating telnet_server\n"),
 	    ok;
 	stop  ->
-	    io:format("[telnet_server] telnet_server stopped\n"),
+	    dbg("telnet_server stopped\n"),
 	    ok
     end.
 
@@ -97,19 +116,21 @@ init_client(#state{client=Sock}=State) ->
     dbg("Server sending: ~p~n",["login: "]),
     R = case gen_tcp:send(Sock,"login: ") of
 	    ok ->
-		loop(State);
+		loop(State, 1);
 	    Error ->
 		Error
 	end,
     _ = gen_tcp:close(Sock),
     R.
 
-loop(State) ->
+loop(State, N) ->
     receive
 	{tcp,_,Data} ->
 	    try handle_data(Data,State) of
 		{ok,State1} ->
-		    loop(State1)
+		    loop(State1, N);
+		closed ->
+		    closed
 	    catch 
 		throw:Error ->
 		    Error
@@ -118,6 +139,11 @@ loop(State) ->
             closed;
 	{tcp_error,_,Error} ->
 	    {error,tcp,Error};
+	disconnect ->
+	    Sock = State#state.client,
+	    dbg("Server closing connection on socket ~p~n", [Sock]),
+	    ok = gen_tcp:close(Sock),
+	    closed;
 	stop ->
 	    stopped
     end.
@@ -130,10 +156,16 @@ handle_data(Data,State) ->
     case get_line(Data,[]) of
 	{Line,Rest} ->
 	    WholeLine = lists:flatten(lists:reverse(State#state.buffer,Line)),
-	    {ok,State1} = do_handle_data(WholeLine,State),
-	    case Rest of
-		[] -> {ok,State1};
-		_ -> handle_data(Rest,State1)
+	    case do_handle_data(WholeLine,State) of
+		{ok,State1} ->
+		    case Rest of
+			[] -> {ok,State1};
+			_ -> handle_data(Rest,State1)
+		    end;
+		{close,State1} ->
+		    dbg("Server closing connection~n",[]),
+		    gen_tcp:close(State1#state.client),
+		    closed
 	    end;
 	false ->
 	    {ok,State#state{buffer=[Data|State#state.buffer]}}
@@ -163,22 +195,29 @@ do_handle_data(Data,#state{authorized=false}=State) ->
     check_user(Data,State);
 do_handle_data(Data,#state{authorized={user,_}}=State) ->
     check_pwd(Data,State);
-do_handle_data("echo "++ Data,State) ->
+do_handle_data("echo " ++ Data,State) ->
     send(Data++"\r\n> ",State),
     {ok,State};
-do_handle_data("echo_no_prompt "++ Data,State) ->
+do_handle_data("echo_no_prompt " ++ Data,State) ->
     send(Data,State),
     {ok,State};
-do_handle_data("echo_ml "++ Data,State) ->
+do_handle_data("echo_ml " ++ Data,State) ->
     Lines = string:tokens(Data," "),
     ReturnData = string:join(Lines,"\n"),
     send(ReturnData++"\r\n> ",State),
     {ok,State};
-do_handle_data("echo_ml_no_prompt "++ Data,State) ->
+do_handle_data("echo_ml_no_prompt " ++ Data,State) ->
     Lines = string:tokens(Data," "),
     ReturnData = string:join(Lines,"\n"),
     send(ReturnData,State),
     {ok,State};
+do_handle_data("disconnect_after " ++WaitStr,State) ->
+    Wait = list_to_integer(string:strip(WaitStr,right,$\n)),
+    dbg("Server will close connection in ~w ms...", [Wait]),
+    erlang:send_after(Wait,self(),disconnect),
+    {ok,State};
+do_handle_data("disconnect" ++_,State) ->
+    {close,State};
 do_handle_data([],State) ->
     send("> ",State),
     {ok,State};
@@ -226,4 +265,4 @@ get_line([],_) ->
 dbg(_F) ->
     dbg(_F,[]).
 dbg(_F,_A) ->
-    io:format("[telnet_server] "++_F,_A).
+    io:format("[telnet_server] " ++ _F,_A).
diff --git a/lib/test_server/src/ts.unix.config b/lib/test_server/src/ts.unix.config
index a34857b9e5..1ba5d9033e 100644
--- a/lib/test_server/src/ts.unix.config
+++ b/lib/test_server/src/ts.unix.config
@@ -3,4 +3,4 @@
 %% Always run a (VNC) X server on host
 %% {xserver, "xserver.example.com:66"}.
 
-{unix,[{telnet,"belegost"},{username,"bofh"},{password,"root"},{keep_alive,true}]}.
+{unix,[{telnet,"belegost"},{username,"telnet-test"},{password,"tset-tenlet"},{keep_alive,true}]}.