[snmp|agent|test] Timestamps and test manager

Added common (formated) timestamp function(s). Made use of
these in the verbosity module (for debug printouts) and in
the test suite(s).

I also *think* I found the cause for some if the test case
failures (timeouts).
For v3 (agent) test cases the test manager makes use of parts
of the agent code: snmp_framework_mib and snmp_user_based_sm_mib.
And since they store their data in snmpa_local_db, that also
needs to be running.
And this was the problem (I think). On some (slow) machines,
the snmpa_local_db process from the *previous* test case
might still be running when the we tried to start it. That meant
that no new snmpa_local_db was started. Instead the old one,
still running but terminating, was retain. For a while. Until
it actually finally stopped. So the next operation towards
snmpa_local_db, insert, simply hanged until the process
terminated.
This in combination with the fact that the packet server process,
which was started using proc_lib, previously called init_ack
before this init was actually done, could actually start and then
at a much later time hang because some operation timed out
(the packet server was hanging).

Yuckety yuck-yuck.

1 files changed, 67 insertions, 4 deletions

diff --git a/lib/snmp/test/snmp_test_mgr_misc.erl b/lib/snmp/test/snmp_test_mgr_misc.erl
index badbbad894..315e3ebd9e 100644
--- a/lib/snmp/test/snmp_test_mgr_misc.erl
+++ b/lib/snmp/test/snmp_test_mgr_misc.erl
@@ -604,6 +604,13 @@ init_usm('version-3', Dir) ->
     ?vlog("init_usm -> create (and init) fake \"agent\" table", []),
     ets:new(snmp_agent_table, [set, public, named_table]),
     ets:insert(snmp_agent_table, {agent_mib_storage, persistent}),
+    %% The local-db process may *still* be running (from a previous
+    %% test case), on the way down, but not yet dead.
+    %% Either way, before we start it, make sure its dead and *gone*!
+    %% How do we do that without getting hung up? Calling the stop
+    %% function, will not do since it uses Timeout=infinity.
+    ?vlog("init_usm -> ensure (old) fake local-db is dead", []),
+    ensure_local_db_dead(),
     ?vlog("init_usm -> try start fake local-db", []),
     case snmpa_local_db:start_link(normal, Dir,
                                    [{sname,     "MGR-LOCAL-DB"},
@@ -612,8 +619,12 @@ init_usm('version-3', Dir) ->
             ?vlog("started: ~p"
                   "~n      ~p", [Pid, process_info(Pid)]);
         {error, {already_started, Pid}} ->
+            LDBInfo = process_info(Pid),
             ?vlog("already started: ~p"
-                  "~n      ~p", [Pid, process_info(Pid)])
+                  "~n      ~p", [Pid, LDBInfo]),
+            ?FAIL({still_running, snmpa_local_db, LDBInfo});
+        {error, Reason} ->
+            ?FAIL({failed_starting, snmpa_local_db, Reason})
     end,
     NameDb = snmpa_agent:db(snmpEngineID),
     ?vlog("init_usm -> try set manager engine-id", []),
@@ -630,6 +641,60 @@ init_usm('version-3', Dir) ->
 init_usm(_Vsn, _Dir) ->
     ok.
 
+ensure_local_db_dead() ->
+    ensure_dead(whereis(snmpa_local_db), 2000).
+
+ensure_dead(Pid, Timeout) when is_pid(Pid) ->
+    MRef = erlang:monitor(process, Pid),
+    try
+        begin
+            ensure_dead_wait(Pid, MRef, Timeout),
+            ensure_dead_stop(Pid, MRef, Timeout),
+            ensure_dead_kill(Pid, MRef, Timeout),
+            exit(failed_stop_local_db)
+        end
+    catch
+        throw:ok ->
+            ok
+    end;
+ensure_dead(_, _) ->
+    ?vlog("ensure_dead -> already dead", []),
+    ok.
+
+ensure_dead_wait(Pid, MRef, Timeout) ->
+    receive
+        {'DOWN', MRef, process, Pid, _Info} ->
+            ?vlog("ensure_dead_wait -> died peacefully", []),
+            throw(ok)
+    after Timeout ->
+            ?vlog("ensure_dead_wait -> giving up", []),
+            ok
+    end.
+
+ensure_dead_stop(Pid, MRef, Timeout) ->
+    StopPid = spawn(fun() -> snmpa_local_db:stop() end),
+    receive
+        {'DOWN', MRef, process, Pid, _Info} ->
+            ?vlog("ensure_dead -> dead (stopped)", []),
+            throw(ok)
+    after Timeout ->
+            ?vlog("ensure_dead_stop -> giving up", []),
+            exit(StopPid, kill),
+            ok
+    end.
+
+ensure_dead_kill(Pid, MRef, Timeout) ->
+    exit(Pid, kill),
+    receive
+        {'DOWN', MRef, process, Pid, _Info} ->
+            ?vlog("ensure_dead -> dead (killed)", []),
+            throw(ok)
+    after Timeout ->
+            ?vlog("ensure_dead_kill -> giving up", []),
+            ok
+    end.
+
+
 
 display_incomming_message(M) ->
     display_message("Incomming",M).
@@ -831,6 +896,4 @@ d(_,_F,_A) ->
 
 print(F, A) ->
     ?PRINT2("MGR_PS " ++ F, A).
-    
-formated_timestamp() ->
-    snmp_test_lib:formated_timestamp().
+