[megaco|test] Fixing the examples test suite

The simple test case was faulty in that the simple example
(which it is testing) require that the MGC and MG run on different
erlang nodes. But the test case did not do this. Instead, it ran
both the MGC and the MG on the test server node, which caused
the test case to fail 1 time of 10.

3 files changed, 289 insertions, 111 deletions

diff --git a/lib/megaco/examples/simple/megaco_simple_mgc.erl b/lib/megaco/examples/simple/megaco_simple_mgc.erl
index f324e17a3a..8a78262b86 100644
--- a/lib/megaco/examples/simple/megaco_simple_mgc.erl
+++ b/lib/megaco/examples/simple/megaco_simple_mgc.erl
@@ -1,7 +1,7 @@
 %%
 %% %CopyrightBegin%
 %% 
-%% Copyright Ericsson AB 2001-2016. All Rights Reserved.
+%% Copyright Ericsson AB 2001-2019. 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.
@@ -193,15 +193,17 @@ stop(Mid) ->
     d("stop -> entry with~n   Mid: ~p", [Mid]),
     Disco = fun(CH) ->
 		    d("stop -> CH: ~p", [CH]),
-		    Reason = stopped_by_user, 
-		    Pid = megaco:conn_info(CH, control_pid),
-		    SendMod = megaco:conn_info(CH, send_mod),
+		    Reason     = stopped_by_user, 
+		    Pid        = megaco:conn_info(CH, control_pid),
+		    SendMod    = megaco:conn_info(CH, send_mod),
 		    SendHandle = megaco:conn_info(CH, send_handle),
 
 		    d("stop -> disconnect", []),
 		    megaco:disconnect(CH, Reason),
+
 		    d("stop -> cancel", []),
-		    megaco:cancel(CH, Reason),
+		    megaco:cancel(CH, Reason), % see handle_disconnect
+
 		    d("stop -> close transport"
 		      "~n   SendMod:    ~p"
 		      "~n   SendHandle: ~p", [SendMod, SendHandle]),
@@ -247,6 +249,7 @@ handle_disconnect(ConnHandle, ProtocolVersion, Reason) ->
       "~n   ProtocolVersion: ~p"
       "~n   Reason:          ~p"
       "", [ConnHandle, ProtocolVersion, Reason]),
+    info_msg("handle_disconnect - cancel outstanding messages~n"),
     megaco:cancel(ConnHandle, Reason), % Cancel the outstanding messages
     ok.
 
@@ -443,6 +446,12 @@ get_arg(Key, Args) ->
 %% DEBUGGING
 %%----------------------------------------------------------------------
 
+info_msg(F) ->
+    info_msg(F, []).
+info_msg(F, A) ->
+    io:format("~p MGC: " ++ F ++ "~n", [self()|A]).
+
+     
 d(F) ->
     d(F, []).
 
diff --git a/lib/megaco/test/megaco_examples_test.erl b/lib/megaco/test/megaco_examples_test.erl
index 3d2d79f413..815e315c27 100644
--- a/lib/megaco/test/megaco_examples_test.erl
+++ b/lib/megaco/test/megaco_examples_test.erl
@@ -31,6 +31,8 @@
 -include_lib("megaco/include/megaco.hrl").
 -include_lib("megaco/include/megaco_message_v1.hrl").
 
+-define(LIB, megaco_test_lib).
+
 t()     -> megaco_test_lib:t(?MODULE).
 t(Case) -> megaco_test_lib:t({?MODULE, Case}).
 
@@ -56,10 +58,19 @@ load_examples() ->
 	{error, Reason} ->
 	    {error, Reason};
 	Dir ->
-	    [code:load_abs(filename:join([Dir, examples, simple, M])) || 
-                M <- example_modules()]
+	    SimpleDir = filename:join([Dir, examples, simple]),
+	    case code:add_path(SimpleDir) of
+		true ->
+		    ok;
+		{error, What} ->
+		    error_logger:error_msg("failed adding examples path: "
+					   "~n   ~p"
+					   "~n", [What]),
+		    {error, {failed_add_path, What}}
+	    end
     end.
 
+
 purge_examples() ->
     case code:lib_dir(megaco) of
 	{error, Reason} ->
@@ -89,124 +100,252 @@ end_per_group(_GroupName, Config) ->
 simple(suite) ->
     [];
 simple(Config) when is_list(Config) ->
-    ?ACQUIRE_NODES(1, Config),
-    d("simple -> proxy start"),
-    ProxyPid = megaco_test_lib:proxy_start({?MODULE, ?LINE}),
+    process_flag(trap_exit, true),
+    d("simple -> create node name(s)"),
+    [_Local, MGC, MG] = ?LIB:mk_nodes(3), %% Grrr
+    Nodes = [MGC, MG],
 
-    d("simple -> start megaco"),
-    ?VERIFY(ok, megaco:start()),
+    d("simple -> start nodes"),
+    ok = ?LIB:start_nodes(Nodes, ?MODULE, ?LINE),
+    
+    MGCId = "MGC",
+    MGId  = "MG",
+
+    d("simple -> MGC proxy start (on ~p)", [MGC]),
+    MGCProxy = megaco_test_lib:proxy_start(MGC, "MGC"),
+    ?SLEEP(1000),
+
+    d("simple -> MG proxy start (on ~p)", [MG]),
+    MGProxy  = megaco_test_lib:proxy_start(MG, "MG"),
+    ?SLEEP(1000),
+
+    MegacoStart       = fun() -> megaco:start() end,
+    MegacoStartVerify =
+	 fun(_, ok)    -> ok;
+	    (Id, Else) -> ?ERROR({failed_starting_megaco, Id, Else})
+	 end,
+
+    d("simple -> start MGC megaco"),
+    exec(MGCProxy, MGCId, MegacoStart,
+	 fun(Res) -> MegacoStartVerify(MGCId, Res) end),
+    %% ?APPLY(MGCProxy, fun() -> ok = megaco:start() end),
+    ?SLEEP(1000),
     
-    start_mgc(ProxyPid),
+    d("simple -> start MG megaco"),
+    exec(MGProxy, MGId, MegacoStart,
+	 fun(Res) -> MegacoStartVerify(MGId, Res) end),
+    %% ?APPLY(MGProxy, fun() -> ok = megaco:start() end),
+    ?SLEEP(1000),
+    
+    d("simple -> start mgc"),
+    start_mgc(MGCProxy),
+    ?SLEEP(1000),
 
-    ?SLEEP(1000), % This is just to make it easier to read the test logs
+    d("simple -> verify MGC info (no mg)"),
+    info(MGCProxy),
+    ?SLEEP(1000),
 
-    start_mg(ProxyPid),
-    
-    ?SLEEP(1000), % This is just to make it easier to read the test logs
+    d("simple -> verify MGC system_info(users) (no mg)"),
+    users(MGCProxy),
+    ?SLEEP(1000),
+
+    d("simple -> start mg"),
+    start_mg(MGProxy),
+    ?SLEEP(1000),
 
-    d("simple -> verify info()"),
-    info(),
+    d("simple -> verify MGC info (mg)"),
+    info(MGCProxy),
+    ?SLEEP(1000),
 
-    d("simple -> verify system_info(users)"),
-    users(),
+    d("simple -> verify MGC system_info(users) (mg)"),
+    users(MGCProxy),
+    ?SLEEP(1000),
+
+    d("simple -> verify MG info"),
+    info(MGProxy),
+    ?SLEEP(1000),
+
+    d("simple -> verify MG system_info(users)"),
+    users(MGProxy),
+    ?SLEEP(1000),
 
     d("simple -> stop mgc"),
-    ?VERIFY(5, length(megaco_simple_mgc:stop())),
-    ?SLEEP(1000), % This is just to make it easier to read the test logs
+    exec(MGCProxy, MGCId,
+	 fun() -> megaco_simple_mgc:stop() end,
+	 fun([_]) -> ok;
+	    (L) when is_list(L) ->
+		 ?ERROR({invalid_users, L});
+	    (X) ->
+		 ?ERROR({invalid_result, X})
+	 end),
+    %% ?VERIFY(5, length()),
+    ?SLEEP(1000),
+
+    d("simple -> verify MGC info (no mgc)"),
+    info(MGCProxy),
+    ?SLEEP(1000),
+
+    d("simple -> verify MG info (no mgc)"),
+    info(MGProxy),
+    ?SLEEP(1000),
+
+    d("simple -> verify MGC system_info(users) (no mgc)",[]),
+    users(MGCProxy),
+    ?SLEEP(1000),
+
+    d("simple -> verify MG system_info(users) (no mgc)",[]),
+    users(MGProxy),
+    ?SLEEP(1000),
+
+    MegacoStop       = fun() -> megaco:stop() end,
+    MegacoStopVerify =
+	 fun(_, ok)    -> ok;
+	    (Id, Else) -> ?ERROR({failed_stop_megaco, Id, Else})
+	 end,
+
+    d("simple -> stop MG megaco",[]),
+    exec(MGProxy, MGId, MegacoStop,
+	 fun(Res) -> MegacoStopVerify(MGId, Res) end),
+    %% ?VERIFY(ok, megaco:stop()),
+    ?SLEEP(1000),
+
+    d("simple -> stop MGC megaco",[]),
+    exec(MGCProxy, MGCId, MegacoStop,
+	 fun(Res) -> MegacoStopVerify(MGCId, Res) end),
+    %% ?VERIFY(ok, megaco:stop()),
+    ?SLEEP(1000),
+
+    d("simple -> kill (exit) MG Proxy: ~p", [MGProxy]),
+    MGProxy ! {stop, self(), normal},
+    receive
+	{'EXIT', MGProxy, _} ->
+	    d("simple -> MG Proxy terminated"),
+	    ok
+    end,
 
-    d("simple -> verify system_info(users)"),
-    users(),
+    d("simple -> kill (exit) MGC Proxy: ~p", [MGCProxy]),
+    MGCProxy ! {stop, self(), normal},
+    receive
+	{'EXIT', MGCProxy, _} ->
+	    d("simple -> MGC Proxy terminated"),
+	    ok
+    end,
 
-    d("simple -> stop megaco"),
-    ?VERIFY(ok, megaco:stop()),
-    ?SLEEP(1000), % This is just to make it easier to read the test logs
+    d("simple -> stop ~p", [MGC]),
+    slave:stop(MGC),
 
-    d("simple -> kill (exit) ProxyPid: ~p", [ProxyPid]),
-    exit(ProxyPid, shutdown), % Controlled kill of transport supervisors
+    d("simple -> stop ~p", [MG]),
+    slave:stop(MG),
 
+    d("simple -> done", []),
     ok.
 
 
-start_mgc(ProxyPid) ->
-    d("start_mgc -> start"),
-    ?APPLY(ProxyPid, fun() -> megaco_simple_mgc:start() end),
+exec(Proxy, Id, Cmd, Verify) ->
+    ?APPLY(Proxy, Cmd),
+    receive
+	{res, Id, Res} ->
+	    Verify(Res)
+    end.
+
+
+start_mgc(Proxy) ->
+    ?APPLY(Proxy,
+	   fun() ->
+		   try megaco_simple_mgc:start() of
+		       Res ->
+			   Res
+		   catch
+		       C:E:S ->
+			   {error, {{catched, C, E, S}}, code:get_path()}
+		   end
+	   end),
     receive
 	{res, _, {ok, MgcAll}} when is_list(MgcAll) ->
-            ?SLEEP(1000), % This is just to make it easier to read the test logs
-            d("start_mgc -> received MGC response: "
-              "~n   ~p", [MgcAll]),
 	    MgcBad = [MgcRes || MgcRes <- MgcAll, element(1, MgcRes) /= ok],
 	    ?VERIFY([], MgcBad),
-            ok;
-        Error ->
-            ?ERROR(Error)
+	    ok;
+	Error ->
+	    ?ERROR(Error)
     end.
 
-start_mg(ProxyPid) ->
-    d("start_mg -> start"),
-    ?APPLY(ProxyPid, fun() -> megaco_simple_mg:start() end),
+
+start_mg(Proxy) ->
+    ?APPLY(Proxy, fun() -> 
+			  try megaco_simple_mg:start() of
+			      Res ->
+				  Res
+			  catch
+			      C:E:S ->
+				  {error, {{catched, C, E, S}}, code:get_path()}
+			  end
+		  end),
     receive
-        {res, _, MgList} when is_list(MgList) andalso (length(MgList) =:= 4) ->
-            ?SLEEP(1000), % This is just to make it easier to read the test logs
-            d("start_mg -> received MG response: "
-              "~n   ~p", [MgList]),
-            Verify = 
-                fun({_MgMid, {TransId, Res}}) when TransId =:= 1 ->
-                        case Res of
-                            {ok, [AR]} when is_record(AR, 'ActionReply') ->
-                                case AR#'ActionReply'.commandReply of
-                                    [{serviceChangeReply, SCR}] ->
-                                        case SCR#'ServiceChangeReply'.serviceChangeResult of
-                                            {serviceChangeResParms, MgcMid}
-                                              when MgcMid =/= asn1_NOVALUE ->
-                                                ok;
-                                            Error ->
-                                                d("start_mg -> "
-                                                  "invalid service "
-                                                  "change parms: "
-                                                  "~n   ~p", [SCR]),
-                                               ?ERROR(Error)
-                                        end;
-                                    Error ->
-                                        d("start_mg -> "
-                                          "invalid service change reply: "
-                                          "~n   ~p", [Error]),
-                                        ?ERROR(Error)
-                                end;
-                            Error ->
-                                d("start_mg -> "
-                                  "invalid result: "
-                                  "~n   ~p", [Error]),
-                                ?ERROR(Error)
-                        end;
-                   (Error) ->
-                        d("start_mg -> "
-                          "invalid reply: "
-                          "~n   ~p", [Error]),
-                        ?ERROR(Error)
-                end,
-            lists:map(Verify, MgList);
-        Error -> 
-            d("start_mg -> "
-              "invalid result: "
-              "~n   ~p", [Error]),
-           ?ERROR(Error)
-    end.    
-                
-info() ->
-    case (catch megaco:info()) of
-	{'EXIT', _} = Error ->
-	    ?ERROR(Error);
-	Info ->
-	    ?LOG("Ok, ~p~n", [Info])
+	{res, _, MGs} when is_list(MGs) andalso (length(MGs) =:= 4) ->
+	    verify_mgs(MGs);
+	Error ->
+	    ?ERROR(Error)
     end.
 
-users() ->
-    case (catch megaco:system_info(users)) of
-	{'EXIT', _} = Error ->
-	    ?ERROR(Error);
-	Users ->
-	    ?LOG("Ok, ~p~n", [Users])
+verify_mgs(MGs) ->
+    Verify = 
+	fun({_MgMid, {TransId, Res}}) when (TransId =:= 1) ->
+		case Res of
+		    {ok, [AR]} when is_record(AR, 'ActionReply') ->
+			case AR#'ActionReply'.commandReply of
+			    [{serviceChangeReply, SCR}] ->
+				case SCR#'ServiceChangeReply'.serviceChangeResult of
+				    {serviceChangeResParms, MgcMid} 
+				      when (MgcMid =/= asn1_NOVALUE) ->
+					ok;
+				    Error ->
+					?ERROR(Error)
+				end;
+			    Error ->
+				?ERROR(Error)
+			end;
+		    Error ->
+			?ERROR(Error)
+		end;
+	   (Error) ->
+		?ERROR(Error)
+	end,
+    lists:map(Verify, MGs).
+    
+    
+info(Proxy) ->
+    ?APPLY(Proxy,
+	   fun() ->
+		   try megaco:info() of
+		       I -> I
+		   catch
+		       C:E:S ->
+			   {error, {C, E, S}}
+		   end
+	   end),
+    receive
+	{res, _, Info} when is_list(Info) ->
+	    ?LOG("Ok, ~p~n", [Info]);
+	{res, _, Error} ->
+	    ?ERROR(Error)
+    end.
+
+
+users(Proxy) ->
+    ?APPLY(Proxy,
+	   fun() ->
+		   try megaco:system_info(users) of
+		       I -> I
+		   catch
+		       C:E:S ->
+			   {error, {C, E, S}}
+		   end
+	   end),
+    receive
+	{res, _, Info} when is_list(Info) ->
+	    ?LOG("Ok, ~p~n", [Info]);
+	{res, _, Error} ->
+	    ?ERROR(Error)
     end.
 
 
diff --git a/lib/megaco/test/megaco_test_lib.erl b/lib/megaco/test/megaco_test_lib.erl
index 5fe03b28e3..0617b96456 100644
--- a/lib/megaco/test/megaco_test_lib.erl
+++ b/lib/megaco/test/megaco_test_lib.erl
@@ -62,6 +62,7 @@
 
          proxy_start/1, proxy_start/2,
 
+         mk_nodes/1,
          start_nodes/3
         ]).
 
@@ -765,6 +766,7 @@ still_alive(Pid) ->
 	    end 
     end.
 
+
 %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
 %% The proxy process
 
@@ -776,32 +778,51 @@ proxy_start(Node, ProxyId) ->
 
 proxy_init(ProxyId, Controller) ->
     process_flag(trap_exit, true),
-    ?LOG("[~p] proxy started by ~p~n",[ProxyId, Controller]),
+    IdStr = proxyid2string(ProxyId),
+    put(id, IdStr),
+    ?LOG("[~s] proxy started by ~p~n", [IdStr, Controller]),
     proxy_loop(ProxyId, Controller).
 
 proxy_loop(OwnId, Controller) ->
     receive
 	{'EXIT', Controller, Reason} ->
-	    p("proxy_loop -> received exit from controller"
+	    pprint("proxy_loop -> received exit from controller"
+                   "~n   Reason: ~p", [Reason]),
+	    exit(Reason);
+	{stop, Controller, Reason} ->
+	    p("proxy_loop -> received stop from controller"
 	      "~n   Reason: ~p"
 	      "~n", [Reason]),
 	    exit(Reason);
+	
 	{apply, Fun} ->
-	    p("proxy_loop -> received apply request~n", []),
+            pprint("proxy_loop -> received apply request"),
 	    Res = Fun(),
-	    p("proxy_loop -> apply result: "
-	      "~n   ~p"
-	      "~n", [Res]),
+            pprint("proxy_loop -> apply result: "
+                   "~n   ~p", [Res]),
 	    Controller ! {res, OwnId, Res},
 	    proxy_loop(OwnId, Controller);
 	OtherMsg ->
-	    p("proxy_loop -> received unknown message: "
-	      "~n  OtherMsg: ~p"
-	      "~n", [OtherMsg]),
+	    pprint("proxy_loop -> received unknown message: "
+                   "~n  ~p", [OtherMsg]),
 	    Controller ! {msg, OwnId, OtherMsg},
 	    proxy_loop(OwnId, Controller)
     end.
 
+proxyid2string(Id) when is_list(Id) ->
+    Id;
+proxyid2string(Id) when is_atom(Id) ->
+    atom_to_list(Id);
+proxyid2string(Id) ->
+    f("~p", [Id]).
+
+pprint(F) ->
+    pprint(F, []).
+
+pprint(F, A) ->
+    io:format("[~s] ~p ~s " ++ F ++ "~n",
+              [get(id), self(), formated_timestamp() | A]).
+
 
 %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
 %% Test server callbacks
@@ -943,7 +964,10 @@ default_config() ->
     [{nodes, default_nodes()}, {ts, megaco}].
 
 default_nodes() ->    
-    mk_nodes(2, []).
+    mk_nodes(3, []).
+
+mk_nodes(N) when (N > 0) ->
+    mk_nodes(N, []).
 
 mk_nodes(0, Nodes) ->
     Nodes;
@@ -983,5 +1007,11 @@ start_nodes([Node | Nodes], File, Line) ->
 start_nodes([], _File, _Line) ->
     ok.
 
+
+%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
+
+f(F, A) ->
+    lists:flatten(io_lib:format(F, A)).
+
 p(F, A) ->
     io:format("~p~w:" ++ F ++ "~n", [self(), ?MODULE |A]).