Implement new telnet logging system

1 files changed, 259 insertions, 212 deletions

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("<b>PROMPT:</b> ~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("<b>PROMPT:</b> ~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("<b>PROMPT:</b> ~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("<b>PROMPT:</b> ~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("<b>PROMPT:</b> ~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("<b>MATCH:</b> ~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("<b>MATCH:</b> ~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,