File 0524-megaco-config-test-More-tweaking-of-mgc-tr... of Package erlang

Overview Repositories Revisions Requests Users Attributes Meta

File 0524-megaco-config-test-More-tweaking-of-mgc-transaction-.patch of Package erlang (Revision a7029ee97b719a45764ae3b135bbdda2)

Currently displaying revision a7029ee97b719a45764ae3b135bbdda2 , Show latest

From 0a097daf0f90bd1901d0cb712bf54f70ab91ad22 Mon Sep 17 00:00:00 2001
From: Micael Karlberg <bmk@erlang.org>
Date: Wed, 17 Mar 2021 20:08:53 +0100
Subject: [PATCH 4/4] [megaco|config|test] More tweaking of (mgc) transaction
 id counter test

---
 lib/megaco/test/megaco_config_SUITE.erl | 85 ++++++++++++++++++++-----
 1 file changed, 69 insertions(+), 16 deletions(-)

diff --git a/lib/megaco/test/megaco_config_SUITE.erl b/lib/megaco/test/megaco_config_SUITE.erl
index f21703f906..79035b3b93 100644
--- a/lib/megaco/test/megaco_config_SUITE.erl
+++ b/lib/megaco/test/megaco_config_SUITE.erl
@@ -657,49 +657,86 @@ start_counter_working_procs([Pid | Pids]) ->
     start_counter_working_procs(Pids).
 
 await_completion_counter_working_procs(Pids) ->
-    await_completion_counter_working_procs(Pids, [], []).
+    await_completion_counter_working_procs(ts(), Pids, [], []).
 
-await_completion_counter_working_procs([], _OKs, [] = _ERRs) ->
+await_completion_counter_working_procs(_TS, [], _OKs, [] = _ERRs) ->
     ok;
-await_completion_counter_working_procs([], _OKs, ERRs) ->
+await_completion_counter_working_procs(_TS, [], _OKs, ERRs) ->
     {error, ERRs};
-await_completion_counter_working_procs(Pids, OKs, ERRs) ->
+await_completion_counter_working_procs(TS, Pids, OKs, ERRs) ->
     receive
 	{'EXIT', Pid, normal} ->
             %% i("counter working process completion[~w, ~w, ~w] -> "
             %%   "Expected exit from counter process: "
+            %%   "~n      Time since last event: ~s"
             %%   "~n      Pid: ~p",
-            %%   [length(Pids), length(OKs), length(ERRs), Pid]),
+            %%   [length(Pids), length(OKs), length(ERRs), tsd(TS), Pid]),
 	    Pids2 = lists:delete(Pid, Pids),
-	    await_completion_counter_working_procs(Pids2, [Pid | OKs], ERRs);
+	    await_completion_counter_working_procs(ts(),
+                                                   Pids2, [Pid | OKs], ERRs);
+
+	{'EXIT', Pid, {timetrap_timeout, _Timeout, Stack} = _Reason} ->
+            e("counter working process completion[~w, ~w, ~w] -> "
+              "Unexpected exit from counter process: test case timeout"
+              "~n      Time since last event: ~s"
+              "~n      Pid:                   ~p"
+              "~n      Stack:                 ~p",
+              [length(Pids), length(OKs), length(ERRs), tsd(TS), Pid, Stack]),
+            %% The test case (timetrap) has timed out, which either means
+            %% we are running on very slow hw or some system functions
+            %% are slowing us down (this test case should never normally
+            %% time out).
+            case megaco_test_global_sys_monitor:events() of
+                [] ->
+                    i("counter working process completion[~w, ~w, ~w] -> idle",
+                      [length(Pids), length(OKs), length(ERRs)]),
+                    ?SKIP("TC idle");
+                SysEvs ->
+                    e("counter working process completion[~w, ~w, ~w] -> "
+                      "system event(s): "
+                      "~n      ~p",
+                      [length(Pids), length(OKs), length(ERRs), SysEvs]),
+                    ?SKIP("TC system events")
+            end;
+
 	{'EXIT', Pid, Reason} ->
+            TSD = tsd(TS),
             e("counter working process completion[~w, ~w, ~w] -> "
               "Unexpected exit from counter process: "
-              "~n      Pid:    ~p"
-              "~n      Reason: ~p",
-              [length(Pids), length(OKs), length(ERRs), Pid, Reason]),
+              "~n      Time since last event: ~s"
+              "~n      Pid:                   ~p"
+              "~n      Reason:                ~p",
+              [length(Pids), length(OKs), length(ERRs), TSD, Pid, Reason]),
 	    Pids2 = lists:delete(Pid, Pids),
-	    await_completion_counter_working_procs(Pids2, OKs, [Pid | ERRs]);
+	    await_completion_counter_working_procs(ts(),
+                                                   Pids2, OKs, [Pid | ERRs]);
 
 	Any ->
+            TSD = tsd(TS),
             e("counter working process completion[~w, ~w, ~w] -> "
               "Unexpected message: "
-              "~n      ~p", [length(Pids), length(OKs), length(ERRs), Any]),
-	    await_completion_counter_working_procs(Pids)
+              "~n      Time since last event: ~s"
+              "~n      ~p",
+              [length(Pids), length(OKs), length(ERRs), TSD, Any]),
+	    await_completion_counter_working_procs(TS, Pids, OKs, ERRs)
 
     after 10000 ->
             %% If nothing has happened for this long, something is wrong:
             %% Check system events
+            TSD = tsd(TS),
             case megaco_test_global_sys_monitor:events() of
                 [] ->
-                    i("counter working process completion[~w, ~w, ~w] -> "
-                      "idle", [length(Pids), length(OKs), length(ERRs)]),
-                    await_completion_counter_working_procs(Pids);
+                    i("counter working process completion[~w, ~w, ~w] -> idle"
+                      "~n      Time since last event: ~s",
+                      [length(Pids), length(OKs), length(ERRs), TSD]),
+                    await_completion_counter_working_procs(TS,
+                                                           Pids, OKs, ERRs);
                 SysEvs ->
                     e("counter working process completion[~w, ~w, ~w] -> "
                       "system event(s): "
+                      "~n      Time since last event: ~s"
                       "~n      ~p",
-                      [length(Pids), length(OKs), length(ERRs), SysEvs]),
+                      [length(Pids), length(OKs), length(ERRs), TSD, SysEvs]),
                     ?SKIP("TC idle with system events")
             end
     end.
@@ -1277,6 +1314,22 @@ try_tc(TCName, Name, Verbosity, Pre, Case, Post) ->
     ?TRY_TC(TCName, Name, Verbosity, Pre, Case, Post).
 
 
+%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
+
+ts() ->
+    erlang:monotonic_time(milli_seconds).
+
+tsd(TS) ->
+    TSD = ts() - TS,
+    if (TSD < 1000) ->
+            ?F("~w ms", [TSD]);
+       (TSD < 60000) ->
+            ?F("~w secs", [TSD div 1000]);
+       true ->
+            ?F("~w mins", [TSD div 60000])
+    end.
+
+
 %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
 
 p(F) ->
-- 
2.26.2

Places

File 0524-megaco-config-test-More-tweaking-of-mgc-transaction-.patch of Package erlang (Revision a7029ee97b719a45764ae3b135bbdda2)

Places