[megaco|test] Convert another (mreq) test case to try-tc

'mreq' test case req_and_pending converted.

3 files changed, 200 insertions, 180 deletions

diff --git a/lib/megaco/test/megaco_mreq_SUITE.erl b/lib/megaco/test/megaco_mreq_SUITE.erl
index d11b872cdf..16af05fe03 100644
--- a/lib/megaco/test/megaco_mreq_SUITE.erl
+++ b/lib/megaco/test/megaco_mreq_SUITE.erl
@@ -33,6 +33,7 @@
          req_and_rep/1,
          req_and_pending/1,
          req_and_cancel/1
+
         ]).
 
 -include_lib("megaco/include/megaco.hrl").
@@ -371,54 +372,60 @@ req_and_pending(suite) ->
 req_and_pending(doc) ->
     [];
 req_and_pending(Config) when is_list(Config) ->
-    put(verbosity, ?TEST_VERBOSITY),
-    put(sname,     "TEST"),
-    i("req_and_pending -> starting"),
-
-    MgcNode = make_node_name(mgc),
-    Mg1Node = make_node_name(mg1),
+    Pre = fun() ->
+                  MgcNode = make_node_name(mgc),
+                  MgNode  = make_node_name(mg),
+                  d("try starting nodes: "
+                    "~n      MgcNode: ~p"
+                    "~n      MgNode:  ~p", [MgcNode, MgNode]),
+                  Nodes = [MgcNode, MgNode], 
+                  ok    = ?START_NODES(Nodes),
+                  Nodes
+          end,
+    Case = fun do_req_and_pending/1,
+    Post = fun(Nodes) ->
+                   d("stop nodes (in the reverse order):"
+                     "~n       ~p", [Nodes]),
+                   ?STOP_NODES(lists:reverse(Nodes))
+           end,
+    try_tc(req_and_pending, Pre, Case, Post).
 
-    d("req_and_pending -> Nodes: "
-      "~n   MgcNode: ~p"
-      "~n   Mg1Node: ~p", 
-      [MgcNode, Mg1Node]),
-    ok = megaco_test_lib:start_nodes([MgcNode, Mg1Node], 
-				     ?FILE, ?LINE),
+do_req_and_pending([MgcNode, MgNode]) ->
 
     %% Start the MGC and MGs
-    i("req_and_pending -> start the MGC"),    
+    i("try start the MGC"),    
     ET = [{text,tcp}, {text,udp}, {binary,tcp}, {binary,udp}],
     {ok, Mgc} = 
 	?MGC_START(MgcNode, {deviceName, "ctrl"}, ET, ?MGC_VERBOSITY),
 
-    i("req_and_pending -> start the MG"),
-    {ok, Mg1} = 
-	?MG_START(Mg1Node, {deviceName, "mg1"}, text, tcp, ?MG_VERBOSITY),
+    i("try start the MG"),
+    {ok, Mg} = 
+	?MG_START(MgNode, {deviceName, "mg"}, text, tcp, ?MG_VERBOSITY),
 
-    i("req_and_pending -> connect the MG"),
-    Res1 = ?MG_SERV_CHANGE(Mg1),
-    d("req_and_pending -> service change result: ~p", [Res1]),
+    i("connect MG (to MFC)"),
+    Res1 = ?MG_SERV_CHANGE(Mg),
+    d("service change result: ~p", [Res1]),
 
     sleep(1000),
 
-    i("req_and_pending -> change request action to pending"),
-    {ok, _} = ?MGC_REQ_PEND(Mgc,3500),
+    i("[MGC] change request action to pending"),
+    {ok, _} = ?MGC_REQ_PEND(Mgc, 3500),
 
-    i("req_and_pending -> send notify request"),
-    {ok, Res2} = ?MG_NOTIF_RAR(Mg1),
-    d("req_and_pending -> notify reply: ~p",[Res2]),
+    i("[MG] send notify request"),
+    {ok, Res2} = ?MG_NOTIF_RAR(Mg),
+    d("notify reply: ~p", [Res2]),
 
     sleep(1000),
 
-    %% Tell MGs to stop
-    i("req_and_pending -> stop the MGs"),
-    ?MG_STOP(Mg1),
+    %% Tell MG to stop
+    i("stop the MG"),
+    ?MG_STOP(Mg),
 
     %% Tell Mgc to stop
-    i("req_and_pending -> stop the MGC"),
+    i("stop the MGC"),
     ?MGC_STOP(Mgc),
 
-    i("req_and_pending -> done", []),
+    i("done", []),
     ok.
 
 
diff --git a/lib/megaco/test/megaco_test_mg.erl b/lib/megaco/test/megaco_test_mg.erl
index 38883c94f0..5979466785 100644
--- a/lib/megaco/test/megaco_test_mg.erl
+++ b/lib/megaco/test/megaco_test_mg.erl
@@ -1,7 +1,7 @@
 %%
 %% %CopyrightBegin%
 %% 
-%% Copyright Ericsson AB 2003-2019. All Rights Reserved.
+%% Copyright Ericsson AB 2003-2020. All Rights Reserved.
 %% 
 %% Licensed under the Apache License, Version 2.0 (the "License");
 %% you may not use this file except in compliance with the License.
@@ -95,9 +95,9 @@ start(Node, Mid, Encoding, Transport, Verbosity) ->
 
 start(Node, Mid, Encoding, Transport, Conf, Verbosity) ->
     d("start mg[~p]: ~p"
-      "~n   Encoding:  ~p"
-      "~n   Transport: ~p"
-      "~n   Conf:      ~p", [Node, Mid, Encoding, Transport, Conf]),
+      "~n      Encoding:  ~p"
+      "~n      Transport: ~p"
+      "~n      Conf:      ~p", [Node, Mid, Encoding, Transport, Conf]),
     RI1    = encoding_config(Encoding),
     RI2    = transport_config(Transport),
     {RI3, Conf1} = transport_opts(Conf), 
@@ -106,17 +106,15 @@ start(Node, Mid, Encoding, Transport, Conf, Verbosity) ->
     Self   = self(),
     Fun    = 
 	fun() ->
-		io:format("LOADER(~p,~p) started~n", [self(),node()]),
+		i("LOADER(~p,~p) started", [self(),node()]),
 		case (catch mg(Self, Verbosity, Config)) of
 		    {'EXIT', Reason} ->
-			io:format("LOADER(~p,~p) terminating with exit"
-				  "~n~p"
-				  "~n", [self(), node(), Reason]),
+			e("LOADER(~p,~p) terminating with exit"
+                          "~n      ~p", [self(), node(), Reason]),
 			exit(Reason);
 		    Else ->
-			io:format("LOADER(~p,~p) terminating with"
-				  "~n~p"
-				  "~n", [self(), node(), Else]),
+			i("LOADER(~p,~p) terminating with"
+                          "~n      ~p", [self(), node(), Else]),
 			Else
 		end
 	end,
@@ -127,12 +125,12 @@ start(Node, Mid, Encoding, Transport, Conf, Verbosity) ->
     NodePing = net_adm:ping(Node), 
     ProcInfo = (catch proc_info(Pid)), 
     i("start -> "
-      "~n   self():           ~p"
-      "~n   node():           ~p"
-      "~n   net_adm:ping(~p): ~p" 
-      "~n   Loader:           ~p"
-      "~n   Monitor ref:      ~p"
-      "~n   Process info:     ~p", 
+      "~n      self():           ~p"
+      "~n      node():           ~p"
+      "~n      net_adm:ping(~p): ~p" 
+      "~n      Loader:           ~p"
+      "~n      Monitor ref:      ~p"
+      "~n      Process info:     ~p", 
       [self(), node(), 
        Node, NodePing, 
        Pid, 
@@ -195,12 +193,12 @@ transport_opts(Config) ->
 
 await_started(Node, MonRef, Pid) ->
     i("await_started -> entry with"
-      "~n   MonRef: ~p"
-      "~n   Pid:    ~p", [MonRef, Pid]),
+      "~n      MonRef: ~p"
+      "~n      Pid:    ~p", [MonRef, Pid]),
     receive
 	{started, Pid} ->
 	    d("await_started ~p - started"
-	      "~n   Process info: ~p", [Pid, (catch proc_info(Pid))]),
+	      "~n      Process Info: ~p", [Pid, (catch proc_info(Pid))]),
 	    true = erlang:monitor_node(Node, false),	    
 	    erlang:demonitor(MonRef),
 	    {ok, Pid};
@@ -210,13 +208,13 @@ await_started(Node, MonRef, Pid) ->
 	    exit({node_down, Node}); 
 
 	{'DOWN', MonRef, process, Pid, Info} ->
-	    i("await_started ~p - received down signal: ~p", 
+	    e("await_started ~p - received down signal: ~p", 
 	      [Pid, Info]),
 	    true = erlang:monitor_node(Node, false),	    
 	    exit({failed_starting, Pid, Info});
 
 	{'EXIT', Pid, Reason} ->
-	    i("await_started ~p - received exit signal: ~p", [Pid, Reason]),
+	    e("await_started ~p - received exit signal: ~p", [Pid, Reason]),
 	    true = erlang:monitor_node(Node, false),	    
 	    exit({failed_starting, Pid, Reason})
 
@@ -226,10 +224,10 @@ await_started(Node, MonRef, Pid) ->
 	    NodePing = net_adm:ping(Node), 
 	    ProcInfo = (catch proc_info(Pid)),
 	    FlushQ = megaco_test_lib:flush(), 
-	    i("await_started ~p - timeout: "
-	      "~n   net_adm:ping(~p):     ~p" 
-	      "~n   Process info:         ~p"
-	      "~n   Messages in my queue: ~p", 
+	    e("await_started ~p - timeout: "
+	      "~n      net_adm:ping(~p):     ~p" 
+	      "~n      Process info:         ~p"
+	      "~n      Messages in my queue: ~p", 
 	      [Pid, Node, NodePing, ProcInfo, FlushQ]),
 	    true = erlang:monitor_node(Node, false),	    
 	    exit({error, timeout})
@@ -371,19 +369,21 @@ mg(Parent, Verbosity, Config) ->
 		{'EXIT', normal} ->
 		    exit(normal);
 		{'EXIT', Reason} ->
-		    i("mg failed with reason:~n   ~p", [Reason]),
+		    e("mg failed with reason:"
+                      "~n      ~p", [Reason]),
 		    exit(Reason);
 		Else ->
-		    i("mg terminated: ~n   ~p", [Else]),
+		    e("mg terminated:"
+                      "~n      ~p", [Else]),
 		    exit({unexpected, Else})
 	    end
     end.
 
 init(Config) ->
     d("init -> entry with"
-      "~n   Config: ~p", [Config]),
+      "~n      Config: ~p", [Config]),
     random_init(),
-    d("init -> random initiated", []),
+    d("init -> random initiated"),
     Mid = get_conf(local_mid, Config),
     d("init -> Mid: ~p", [Mid]),
     RI  = get_conf(receive_info, Config),
@@ -462,8 +462,8 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
 	    i("loop -> enable_test_code: ~p, ~p", [Tag, Fun]),
 	    Reply = (catch ets:insert(megaco_test_data, {Tag, Fun})),
 	    d("loop -> enable_test_code -> "
-	      "~n   Reply:                          ~p"
-	      "~n   ets:tab2list(megaco_test_data): ~p", 
+	      "~n      Reply:                          ~p"
+	      "~n      ets:tab2list(megaco_test_data): ~p", 
 	      [Reply,ets:tab2list(megaco_test_data)]),
 	    server_reply(Parent, enable_test_code_reply, Reply),
 	    loop(evs(S, {enable_test_code, Tag}));
@@ -476,13 +476,13 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
 
 	%% Give me statistics
 	{statistics, Parent} ->
-	    i("loop -> got request for statistics", []),
+	    i("loop -> got request for statistics"),
 	    Stats = do_get_statistics(Mid),
 	    server_reply(Parent, statistics_reply, {ok, Stats}),
 	    loop(evs(S, stats)); 
 
 	{reset_stats, Parent} ->
-	    i("loop -> got request to reset stats counters", []),
+	    i("loop -> got request to reset stats counters"),
 	    do_reset_stats(Mid),
 	    server_reply(Parent, reset_stats_ack, ok),
 	    loop(evs(S, rst_stats));
@@ -518,11 +518,11 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
 	%% No server-reply here. Since the service change is 
 	%% async, the reply (from the MGC) will come later.
 	{service_change, Parent} ->
-	    i("loop -> received request to perform service change", []),
+	    i("loop -> received request to perform service change"),
 	    S1 = 
 		case (catch do_service_change(S)) of
 		    {ok, MG} ->
-			d("loop -> service change initiated", []),
+			d("loop -> service change initiated"),
 			MG;
 		    Error ->
 			d("loop -> service change failed: ~p", [Error]),
@@ -538,16 +538,16 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
 	    loop(evs(S#mg{group_size = N}, {grp_reqs, N})); 
 
 	{{ack_info, To}, Parent} ->
-	    i("loop -> received request to inform about received ack's ", []),
+	    i("loop -> received request to inform about received ack's"),
 	    loop(evs(S#mg{ack_info = To}, {acki, To}));
 
 	{{rep_info, To}, Parent} ->
-	    i("loop -> received request to inform about received rep's ", []),
+	    i("loop -> received request to inform about received rep's "),
 	    loop(evs(S#mg{rep_info = To}, {repi, To}));
 
 	%% Make a sync-call
 	{notify_request, Parent} ->
-	    i("loop -> received request to send notify request ", []),
+	    i("loop -> received request to send notify request "),
 	    {Res, S1} = do_handle_notify_request(S),
 	    d("loop -> notify request result: ~p", [Res]),
 	    loop(evs(S1, not_req));
@@ -564,7 +564,7 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
 
 	%% cancel requests
 	{cancel_request, Reason, Parent} ->
-	    i("loop -> received request to cancel (all) megaco requests ", []),
+	    i("loop -> received request to cancel (all) megaco requests"),
 	    Res = do_cancel_requests(Mid, Reason),
 	    server_reply(Parent, cancel_request_reply, Res),
 	    loop(evs(S, {creq, Reason}));
@@ -600,25 +600,28 @@ loop(#mg{parent = Parent, mid = Mid} = S) ->
 
 	%% Megaco callback messages
 	{request, Request, Mid, From} ->
-	    d("loop -> received megaco request: ~n   ~p"
-	      "~n   Mid:  ~p"
-	      "~n   From: ~p", 
+	    d("loop -> received megaco request: "
+              "~n      ~p"
+	      "~n      Mid:  ~p"
+	      "~n      From: ~p", 
 	      [Request, Mid, From]),
 	    {Reply, S1} = handle_megaco_request(S, Request),
-	    d("loop -> send (megaco callback) request reply: ~n~p", [Reply]),
+	    d("loop -> send (megaco callback) request reply:"
+              "~n      ~p", [Reply]),
 	    From ! {reply, Reply, self()},
 	    loop(evs(S1, {req, {Request, Mid, From}}));
 
 
 	{'EXIT', Pid, Reason} -> 
 	    i("loop -> received exit signal from ~p: "
-              "~n   ~p", [Pid, Reason]),
+              "~n      ~p", [Pid, Reason]),
 	    S1 = handle_exit(S, Pid, Reason),
 	    loop(evs(S1, {exit, {Pid, Reason}}));
 
 
 	Invalid ->
-	    error_msg("received invalid request: ~n~p", [Invalid]),
+	    error_msg("received invalid request: "
+                      "~n   ~p", [Invalid]),
 	    loop(evs(S, {invalid, Invalid}))
 
     end.
@@ -793,10 +796,10 @@ do_service_change(#mg{state = State} = MG) ->
 
 do_service_change(ConnHandle, Method, EAF, Reason) ->
     d("send service change using:"
-      "~n   ConnHandle: ~p"
-      "~n   Method:     ~p"
-      "~n   EAF:        ~p"
-      "~n   Reason:     ~p", [ConnHandle, Method, EAF, Reason]),
+      "~n      ConnHandle: ~p"
+      "~n      Method:     ~p"
+      "~n      EAF:        ~p"
+      "~n      Reason:     ~p", [ConnHandle, Method, EAF, Reason]),
     SCP    = cre_serviceChangeParm(Method, [Reason]),
     TermId = [?megaco_root_termination_id],
     SCR    = cre_serviceChangeReq(TermId, SCP),
@@ -816,7 +819,7 @@ do_handle_notify_request(#mg{mid             = Mid,
     {ok, MG#mg{req_handler = Pid}};
 do_handle_notify_request(#mg{state = State} = MG) ->
     d("do_handle_notify_request -> entry with"
-      "~n   State: ~p", [State]),
+      "~n      State: ~p", [State]),
     {{error, {invalid_state, State}}, MG}.
 
 
@@ -867,7 +870,7 @@ handle_exit(#mg{parent = Pid} = S, Pid, Reason) ->
 
 handle_exit(#mg{parent = Parent, req_handler = Pid} = MG, Pid, Reason) ->
     error_msg("received unexpected exit from the request handler:"
-	      "~n   ~p", [Reason]),
+	      "~n      ~p", [Reason]),
     server_reply(Parent, notify_request_reply, 
 		 {error, {request_handler_exit, Reason}}),
     MG#mg{req_handler = undefined};
@@ -875,14 +878,14 @@ handle_exit(#mg{parent = Parent, req_handler = Pid} = MG, Pid, Reason) ->
 handle_exit(#mg{parent = Parent, mload_info = {Loaders0, Ok, Err}} = MG, 
 	    Pid, loader_done) ->
     d("handle_exit(loader_done) -> entry when"
-      "~n   Loaders0: ~p"
-      "~n   Ok:       ~p"
-      "~n   Err:      ~p", [Loaders0, Ok, Err]),
+      "~n      Loaders0: ~p"
+      "~n      Ok:       ~p"
+      "~n      Err:      ~p", [Loaders0, Ok, Err]),
     Loaders = lists:delete(Pid, Loaders0),
     LoadInfo =
 	case Loaders of
 	    [] ->
-		d("handle_exit -> multi load done", []),
+		d("handle_exit -> multi load done"),
 		server_reply(Parent, apply_multi_load_ack, {ok, Ok+1, Err}),
 		undefined;
 	    _ ->
@@ -895,10 +898,10 @@ handle_exit(#mg{parent = Parent, mload_info = {Loaders, Ok, Err}} = MG,
 	    Pid, Reason) 
   when length(Loaders) > 0 ->
     d("handle_exit -> entry when"
-      "~n   Reason:  ~p"
-      "~n   Loaders: ~p"
-      "~n   Ok:      ~p"
-      "~n   Err:     ~p", [Reason, Loaders, Ok, Err]),
+      "~n      Reason:  ~p"
+      "~n      Loaders: ~p"
+      "~n      Ok:      ~p"
+      "~n      Err:     ~p", [Reason, Loaders, Ok, Err]),
     case lists:delete(Pid, Loaders) of
 	[] -> 
 	    %% since we cannot be empty prior the delete, 
@@ -907,15 +910,15 @@ handle_exit(#mg{parent = Parent, mload_info = {Loaders, Ok, Err}} = MG,
 	    MG#mg{mload_info = undefined};
 	Loaders ->
 	    %% Could not be this MG, so go on to the next
-	    error_msg("received unexpected exit signal from ~p:~n~p", 
-		      [Pid, Reason]);
+	    error_msg("received unexpected exit signal from ~p:"
+                      "~n   ~p", [Pid, Reason]);
 	Loaders1 ->
 	    %% Not empty, but we removed one
 	    MG#mg{mload_info = {Loaders1,Ok,Err+1}}
     end;
 handle_exit(_MG, Pid, Reason) ->
-    error_msg("received unexpected exit signal from ~p:~n~p", 
-	      [Pid, Reason]).
+    error_msg("received unexpected exit signal from ~p:"
+              "~n   ~p", [Pid, Reason]).
 
 		      
 parse_receive_info(RI, RH) ->
@@ -949,10 +952,10 @@ start_transport(_, _, #megaco_receive_handle{send_mod = Mod}, _TO) ->
 
 start_tcp(MgcPort, MgcHost, RH, TO) ->
     d("start tcp transport: "
-      "~n   MGC Port:          ~p"
-      "~n   MGC Host:          ~p"
-      "~n   Receive handle:    ~p"
-      "~n   Transport options: ~p", [MgcPort, MgcHost, RH, TO]),
+      "~n      MGC Port:          ~p"
+      "~n      MGC Host:          ~p"
+      "~n      Receive handle:    ~p"
+      "~n      Transport options: ~p", [MgcPort, MgcHost, RH, TO]),
     case megaco_tcp:start_transport() of
 	{ok, Sup} ->
 	    d("tcp transport started: ~p", [Sup]),
@@ -1026,11 +1029,11 @@ megaco_udp_connect(MgcPort, MgcHost, RH, Handle, ControlPid) ->
 
 update_load_times(#mg{load_counter = 0} = MG, Times) ->
     d("update_load_times(0) -> entry with"
-      "~n   Times: ~p", [Times]),
+      "~n      Times: ~p", [Times]),
     {ok, MG#mg{load_counter = Times}};
 update_load_times(#mg{load_counter = N}, Times) ->
     d("update_load_times(~p) -> entry with"
-      "~n   Times: ~p", [N, Times]),
+      "~n      Times: ~p", [N, Times]),
     {error, {already_counting, N}}.
 
 
@@ -1050,14 +1053,14 @@ do_apply_load(#mg{parent          = Parent,
 		  group_size      = Sz, 
 		  load_counter    = N0} = MG, CH) ->
     d("do_apply_load -> entry with"
-      "~n   Mode: ~p"
-      "~n   Sz:   ~p"
-      "~n   N0:   ~p", [Mode, Sz, N0]),
+      "~n      Mode: ~p"
+      "~n      Sz:   ~p"
+      "~n      N0:   ~p", [Mode, Sz, N0]),
     {NofSent, Actions, ReplyData} = make_notify_request(N0, Sz),
     d("do_apply_load -> notifications constructed:"
-      "~n   NofSent:   ~p"
-      "~n   Actions:   ~p"
-      "~n   ReplyData: ~p", [NofSent, Actions, ReplyData]),
+      "~n      NofSent:   ~p"
+      "~n      Actions:   ~p"
+      "~n      ReplyData: ~p", [NofSent, Actions, ReplyData]),
     N = N0 - NofSent,
     case Mode of
 	sync ->
@@ -1084,9 +1087,9 @@ do_apply_load(#mg{parent          = Parent,
 
 start_notify_request_handler(EAF, CH, N) ->
     d("start_notify_request_handler -> entry with"
-      "~n   EAF: ~p"
-      "~n   CH:  ~p"
-      "~n   N:   ~p", [EAF, CH, N]),
+      "~n      EAF: ~p"
+      "~n      CH:  ~p"
+      "~n      N:   ~p", [EAF, CH, N]),
     Env = get(),
     spawn_link(?MODULE, notify_request_handler_main, [self(), Env, EAF, CH, N]).
 
@@ -1094,13 +1097,13 @@ notify_request_handler_main(Parent, Env, EAF, CH, N) ->
     F = fun({Tag, Val}) -> put(Tag, Val) end,
     lists:foreach(F, Env),
     d("notify_request_handler_main -> entry with"
-      "~n   Parent: ~p"
-      "~n   EAF:    ~p"
-      "~n   CH:     ~p"
-      "~n   N:      ~p", [Parent, EAF, CH, N]),
+      "~n      Parent: ~p"
+      "~n      EAF:    ~p"
+      "~n      CH:     ~p"
+      "~n      N:      ~p", [Parent, EAF, CH, N]),
     Res = do_notify_request(EAF, CH, N),
     d("notify_request_handler_main -> notify complete:"
-      "~n   Res: ~p", [Res]),
+      "~n      Res: ~p", [Res]),
     Parent ! {notify_request_complete, {ok, Res}, self()},
     unlink(Parent),
     exit(normal).
@@ -1220,7 +1223,7 @@ handle_megaco_request(#mg{req_handler = Pid} = MG,
 		      {handle_disconnect, _CH, _PV, R}) 
   when is_pid(Pid) ->
     d("handle_megaco_request(handle_disconnect) -> entry with"
-      "~n   Pid: ~p", [Pid]),
+      "~n      Pid: ~p", [Pid]),
     Error = {error, {disconnected, R}},
     self() ! {notify_request_complete, Error, Pid},
     unlink(Pid),
@@ -1238,19 +1241,19 @@ handle_megaco_request(#mg{req_handler = Pid} = MG,
 		      {handle_message_error, CH, PV, ED}) 
   when is_pid(Pid) ->
     d("handle_megaco_request(handle_message_error) -> entry with"
-      "~n   Pid:    ~p"
-      "~n   CH:     ~p"
-      "~n   PV:     ~p"
-      "~n   ED:     ~p", [Pid, CH, PV, ED]),    
+      "~n      Pid:    ~p"
+      "~n      CH:     ~p"
+      "~n      PV:     ~p"
+      "~n      ED:     ~p", [Pid, CH, PV, ED]),    
     self() ! {notify_request_complete, ED, Pid},
     unlink(Pid),
     exit(Pid, kill),
     {no_reply, MG#mg{req_handler = undefined}};
 handle_megaco_request(MG, {handle_message_error, CH, PV, ED}) ->
     d("handle_megaco_request(handle_message_error) -> entry with"
-      "~n   CH:     ~p"
-      "~n   PV:     ~p"
-      "~n   ED:     ~p", [CH, PV, ED]),    
+      "~n      CH:     ~p"
+      "~n      PV:     ~p"
+      "~n      ED:     ~p", [CH, PV, ED]),    
     {no_reply, MG};
 
 handle_megaco_request(MG, {handle_trans_request, _CH, _PV, _AR}) ->
@@ -1283,31 +1286,31 @@ handle_megaco_request(MG, {handle_trans_ack, _CH, _PV, _AS, _AD}) ->
 do_handle_trans_reply(#mg{parent = Parent, state = connecting} = MG,
 		      CH, _PV, {ok, Rep}, _RD) ->
     d("do_handle_trans_reply(connecting) -> entry with"
-      "~n   CH:     ~p"
-      "~n   Rep:    ~p", [CH, Rep]),
+      "~n      CH:     ~p"
+      "~n      Rep:    ~p", [CH, Rep]),
     server_reply(Parent, service_change_reply, ok),
     {ok, MG#mg{state = connected}};
 do_handle_trans_reply(#mg{parent = Parent, load_counter = 0} = MG,
 		      CH, _PV, {ok, Rep}, _RD) ->
     d("do_handle_trans_reply(load_counter = 0) -> entry with"
-      "~n   CH:     ~p"
-      "~n   Rep:    ~p", [CH, Rep, Parent]),
+      "~n      CH:     ~p"
+      "~n      Rep:    ~p", [CH, Rep, Parent]),
     handle_trans_reply_verify_act(Rep),
     server_reply(Parent, load_complete, ok),
     {ok, MG#mg{reply_counter = 0}};
 do_handle_trans_reply(#mg{reply_counter = 0} = MG,
 		      CH, _PV, {ok, Rep}, _RD) ->
     d("do_handle_trans_reply(reply_counter = 0) -> entry with"
-      "~n   CH:     ~p"
-      "~n   Rep:    ~p", [CH, Rep]),
+      "~n      CH:     ~p"
+      "~n      Rep:    ~p", [CH, Rep]),
     handle_trans_reply_verify_act(Rep),
     apply_load_timer(),
     {ok, MG};
 do_handle_trans_reply(#mg{reply_counter = N} = MG,
 		      CH, _PV, {ok, Rep}, _RD) ->
     d("do_handle_trans_reply(reply_counter = ~p) -> entry with"
-      "~n   CH:     ~p"
-      "~n   Rep:    ~p", [N, CH, Rep]),
+      "~n      CH:     ~p"
+      "~n      Rep:    ~p", [N, CH, Rep]),
     handle_trans_reply_verify_act(Rep),
     apply_load_timer(),
     {ok, MG#mg{reply_counter = N-1}};
@@ -1529,11 +1532,18 @@ num2str(N, Val) ->
 
 %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
 
+%% e(F) ->
+%%     i(F, []).
+
+e(F, A) ->
+    print(error, get(verbosity), "ERROR", F, A).
+
+
 i(F) ->
     i(F, []).
 
 i(F, A) ->
-    print(info, get(verbosity), "", F, A).
+    print(info, get(verbosity), "INFO", F, A).
 
 
 d(F) ->
@@ -1543,15 +1553,16 @@ d(F, A) ->
     print(debug, get(verbosity), "DBG", F, A).
 
 
+printable(error, _)   -> true;
 printable(_, debug)   -> true;
 printable(info, info) -> true;
 printable(_,_)        -> false.
 
 print(Severity, Verbosity, P, F, A) ->
-    print(printable(Severity,Verbosity), P, F, A).
+    print(printable(Severity, Verbosity), P, F, A).
 
 print(true, P, F, A) ->
-    io:format("*** [~s] ~s ~p ~s ***"
+    io:format("*** [~s] [~s] ~p ~s ***"
               "~n   " ++ F ++ "~n~n", 
               [?FTS(), P, self(), get(sname) | A]);
 print(_, _, _, _) ->
diff --git a/lib/megaco/test/megaco_test_mgc.erl b/lib/megaco/test/megaco_test_mgc.erl
index 4e8329c0d1..8a9b182368 100644
--- a/lib/megaco/test/megaco_test_mgc.erl
+++ b/lib/megaco/test/megaco_test_mgc.erl
@@ -1,7 +1,7 @@
 %%
 %% %CopyrightBegin%
 %% 
-%% Copyright Ericsson AB 2003-2019. All Rights Reserved.
+%% Copyright Ericsson AB 2003-2020. All Rights Reserved.
 %% 
 %% Licensed under the Apache License, Version 2.0 (the "License");
 %% you may not use this file except in compliance with the License.
@@ -90,7 +90,9 @@ start(Node, Mid, ET, Verbosity) ->
     start(Node, Mid, ET, Conf, Verbosity).
 
 start(Node, Mid, ET, Conf, Verbosity) ->
-    d("start mgc[~p]: ~p", [Node, Mid]),
+    d("start mgc[~p]: ~p"
+      "~n      ET:   ~p"
+      "~n      Conf: ~p", [Node, Mid, ET, Conf]),
     RI = {receive_info, mk_recv_info(ET)},
     Config = [{local_mid, Mid}, RI] ++ Conf,
     Pid = spawn_link(Node, ?MODULE, mgc, [self(), Verbosity, Config]),
@@ -160,13 +162,13 @@ await_started(Pid) ->
 	    {ok, Pid};
 	{'EXIT', Pid, 
 	 {failed_starting_tcp_listen, {could_not_start_listener, {gen_tcp_listen, eaddrinuse}}}} ->
-	    i("await_started ~p: address already in use", [Pid]),
+	    e("await_started ~p: address already in use", [Pid]),
 	    ?SKIP(eaddrinuse);
 	{'EXIT', Pid, Reason} ->
-	    i("await_started ~p: received exit signal: ~p", [Pid, Reason]),
+	    e("await_started ~p: received exit signal: ~p", [Pid, Reason]),
 	    exit({failed_starting, Pid, Reason})
     after 10000 ->
-	    i("await_started ~p: timeout", [Pid]),
+	    e("await_started ~p: timeout", [Pid]),
 	    exit({error, timeout})
     end.
 
@@ -365,19 +367,19 @@ loop(S) ->
 	    loop(evs(S#mgc{dsi_timer = NewTimer}, {dsi, Time}));
 
 	{stop, Parent} when S#mgc.parent =:= Parent ->
-	    i("loop -> stopping", []),
+	    i("loop -> stopping"),
 	    display_system_info(S#mgc.mid, "at finish "),
 	    cancel_timer(S#mgc.dsi_timer),
   	    Mid = S#mgc.mid,
 	    (catch close_conns(Mid)),
 	    megaco:stop_user(Mid),
 	    application:stop(megaco),
-	    i("loop -> stopped", []),
+	    i("loop -> stopped"),
 	    server_reply(Parent, stopped, ok),
 	    done(evs(S, stop), normal);
 
 	{{disconnect, Reason}, Parent} when S#mgc.parent == Parent ->
-	    i("loop -> disconnecting", []),
+	    i("loop -> disconnecting"),
   	    Mid = S#mgc.mid,
 	    [Conn|_] = megaco:user_info(Mid, connections),
 	    Res = megaco:disconnect(Conn, {self(), Reason}),
@@ -485,8 +487,8 @@ loop(S) ->
 
 	%% Megaco callback messages
 	{request, Request, From} ->
-	    d("loop -> received megaco request from ~p:~n~p", 
-	      [From, Request]),
+	    d("loop -> received megaco request from ~p:"
+              "~n      ~p", [From, Request]),
 	    {Reply, S1} = handle_megaco_request(Request, S),
 	    d("loop -> send request reply: ~n~p", [Reply]),
 	    reply(From, Reply),
@@ -494,17 +496,17 @@ loop(S) ->
 
 
 	{ack_info, To, Parent} when S#mgc.parent == Parent ->
-	    i("loop -> received request to inform about received ack's ", []),
+	    i("loop -> received request to inform about received ack's "),
 	    loop(evs(S#mgc{ack_info = To}, {acki, To}));
 
 
 	{abort_info, To, Parent} when S#mgc.parent == Parent ->
-	    i("loop -> received request to inform about received aborts ", []),
+	    i("loop -> received request to inform about received aborts "),
 	    loop(evs(S#mgc{abort_info = To}, {abi, To}));
 
 
 	{req_info, To, Parent} when S#mgc.parent == Parent ->
-	    i("loop -> received request to inform about received req's ", []),
+	    i("loop -> received request to inform about received req's "),
 	    loop(evs(S#mgc{req_info = To}, {reqi, To}));
 
 
@@ -516,16 +518,16 @@ loop(S) ->
 
 	{'EXIT', Pid, Reason} when S#mgc.tcp_sup =:= Pid ->
 	    error_msg("MGC received unexpected exit "
-		      "from TCP transport supervisor (~p):~n~p", 
-		      [Pid, Reason]),
-	    i("loop -> [tcp] exiting", []),
+		      "from TCP transport supervisor (~p):"
+                      "~n   ~p", [Pid, Reason]),
+	    i("loop -> [tcp] exiting"),
 	    display_system_info(S#mgc.mid, "at bad finish (tcp) "),
 	    cancel_timer(S#mgc.dsi_timer),
   	    Mid = S#mgc.mid,
 	    (catch close_conns(Mid)),
 	    megaco:stop_user(Mid),
 	    application:stop(megaco),
-	    i("loop -> stopped", []),
+	    i("loop -> stopped"),
 	    StopReason = {error, {tcp_terminated, Pid, Reason}}, 
 	    server_reply(S#mgc.parent, stopped, StopReason),
 	    done(evs(S, {tcp_sup_exit, Reason}), StopReason);
@@ -533,16 +535,16 @@ loop(S) ->
 
 	{'EXIT', Pid, Reason} when S#mgc.udp_sup =:= Pid ->
 	    error_msg("MGC received unexpected exit "
-		      "from UDP transport supervisor (~p):~n~p", 
-		      [Pid, Reason]),
-	    i("loop -> [udp] exiting", []),
+		      "from UDP transport supervisor (~p):"
+                      "~n   ~p", [Pid, Reason]),
+	    i("loop -> [udp] exiting"),
 	    display_system_info(S#mgc.mid, "at bad finish (udp) "),
 	    cancel_timer(S#mgc.dsi_timer),
   	    Mid = S#mgc.mid,
 	    (catch close_conns(Mid)),
 	    megaco:stop_user(Mid),
 	    application:stop(megaco),
-	    i("loop -> stopped", []),
+	    i("loop -> stopped"),
 	    StopReason = {error, {udp_terminated, Pid, Reason}}, 
 	    server_reply(S#mgc.parent, stopped, StopReason),
 	    done(evs(S, {udp_sup_exit, Reason}), StopReason);
@@ -619,13 +621,13 @@ parse_receive_info(RI, RH) ->
 
 parse_receive_info([], _RH, Transports) ->
     d("parse_receive_info -> done when"
-      "~n   Transports: ~p", [Transports]),
+      "~n      Transports: ~p", [Transports]),
     Transports;
 parse_receive_info([RI|RIs], RH, Transports) ->
     d("parse_receive_info -> parse receive info"),
     case (catch parse_receive_info1(RI, RH)) of
 	{error, Reason} ->
-	    i("failed parsing receive info: ~p~n~p", [RI, Reason]),
+	    e("failed parsing receive info: ~p~n~p", [RI, Reason]),
 	    exit({failed_parsing_recv_info, RI, Reason});
 	RH1 ->
 	    parse_receive_info(RIs, RH, [RH1|Transports])
@@ -646,9 +648,9 @@ parse_receive_info1(RI, RH) ->
 				   encoding_mod    = EM,
 				   encoding_config = EC},
     d("parse_receive_info1 -> "
-      "~n   Transport Opts: ~p"
-      "~n   Port:           ~p"
-      "~n   Receive handle: ~p", [TO, TP, RH1]),
+      "~n      Transport Opts: ~p"
+      "~n      Port:           ~p"
+      "~n      Receive handle: ~p", [TO, TP, RH1]),
     {TO, TP, RH1}.
 
 
@@ -839,34 +841,34 @@ handle_megaco_request({handle_trans_reply, _CH, _PV, _AR, _RD}, S) ->
 handle_megaco_request({handle_trans_ack, CH, PV, AS, AD}, 
 		      #mgc{ack_info = P} = S) when is_pid(P) ->
     d("handle_megaco_request(handle_trans_ack,~p) -> entry when"
-      "~n   CH: ~p"
-      "~n   PV: ~p"
-      "~n   AS: ~p"
-      "~n   AD: ~p", [P, CH, PV, AS, AD]),
+      "~n      CH: ~p"
+      "~n      PV: ~p"
+      "~n      AS: ~p"
+      "~n      AD: ~p", [P, CH, PV, AS, AD]),
     P ! {ack_received, self(), AS},
     {ok, S};
 
 handle_megaco_request({handle_trans_ack, CH, PV, AS, AD}, S) ->
     d("handle_megaco_request(handle_trans_ack) -> entry with"
-      "~n   Conn Handle:  ~p"
-      "~n   Prot Version: ~p"
-      "~n   Ack Status:   ~p"
-      "~n   Ack Data:     ~p", [CH, PV, AS, AD]),
+      "~n      Conn Handle:  ~p"
+      "~n      Prot Version: ~p"
+      "~n      Ack Status:   ~p"
+      "~n      Ack Data:     ~p", [CH, PV, AS, AD]),
     {ok, S};
 
 handle_megaco_request({handle_unexpected_trans, CH, PV, TR}, S) ->
     d("handle_megaco_request(handle_unexpected_trans) -> entry with"
-      "~n   CH: ~p"
-      "~n   PV: ~p"
-      "~n   TR: ~p", [CH, PV, TR]),
+      "~n      CH: ~p"
+      "~n      PV: ~p"
+      "~n      TR: ~p", [CH, PV, TR]),
     {ok, S};
 
 handle_megaco_request({handle_trans_request_abort, CH, PV, TI, Handler}, S) ->
     d("handle_megaco_request(handle_trans_request_abort) -> entry with"
-      "~n   CH:      ~p"
-      "~n   PV:      ~p"
-      "~n   TI:      ~p"
-      "~n   Handler: ~p", [CH, PV, TI, Handler]),
+      "~n      CH:      ~p"
+      "~n      PV:      ~p"
+      "~n      TI:      ~p"
+      "~n      Handler: ~p", [CH, PV, TI, Handler]),
     Reply = 
 	case S#mgc.abort_info of
 	    P when is_pid(P) ->
@@ -881,8 +883,8 @@ handle_megaco_request({handle_trans_request_abort, CH, PV, TI, Handler}, S) ->
 do_handle_trans_request(CH, PV, ARs, 
 			#mgc{req_action = Action, req_timeout = To} = S) ->
     d("do_handle_megaco_request(handle_trans_request) -> entry with"
-      "~n   Action: ~p"
-      "~n   To:     ~p", [Action, To]),
+      "~n      Action: ~p"
+      "~n      To:     ~p", [Action, To]),
     case handle_act_requests(CH, PV, ARs, Action) of
 	{pending_ignore, ActReqs} ->
 	    {{pending, ActReqs}, S#mgc{req_action = ignore}};
@@ -958,8 +960,8 @@ handle_notify_req(CH, PV, CtxId,
 
 handle_event(_CH, _PV, _Cid, Tid, EvDesc) ->
     d("handle_event -> received"
-      "~n   EvDesc: ~p"
-      "~n   Tid:    ~p", [EvDesc, Tid]),
+      "~n      EvDesc: ~p"
+      "~n      Tid:    ~p", [EvDesc, Tid]),
     {notifyReply, cre_notifyRep(Tid)}.
     
 
@@ -1210,14 +1212,14 @@ i(F) ->
     i(F, []).
 
 i(F, A) ->
-    print(info, get(verbosity), "", F, A).
+    print(info, get(verbosity), "INFO", F, A).
 
 
 d(F) ->
     d(F, []).
 
 d(F, A) ->
-    print(debug, get(verbosity), "DBG: ", F, A).
+    print(debug, get(verbosity), "DBG", F, A).
 
 
 printable(error, _)   -> true;
@@ -1234,7 +1236,7 @@ print(_, _, _, _) ->
     ok.
 
 print(P, F, A) ->
-    io:format("*** [~s] ~s ~p ~s ***"
+    io:format("*** [~s] [~s] ~p ~s ***"
 	      "~n   " ++ F ++ "~n~n", 
 	      [?FTS(), P, self(), get(sname) | A]).