Merge branch 'bmk/snmp/agent_test_expect/OTP-9748' into bmk/snmp/snmp4213_integration

3 files changed, 224 insertions, 119 deletions

diff --git a/lib/snmp/test/snmp_agent_test.erl b/lib/snmp/test/snmp_agent_test.erl
index 468280db02..426524be4d 100644
--- a/lib/snmp/test/snmp_agent_test.erl
+++ b/lib/snmp/test/snmp_agent_test.erl
@@ -92,7 +92,8 @@ all() ->
     Conf1 ++ Conf2.
 
 groups() -> 
-    [{all_tcs, [], cases()},
+    [
+     {all_tcs, [], cases()},
      {mib_storage, [],
       [
        {group, mib_storage_ets}, 
@@ -1321,7 +1322,7 @@ finish_v3(Config) when is_list(Config) ->
 
 
 mt_cases() -> 
-[multi_threaded, mt_trap].
+    [multi_threaded, mt_trap].
 
 init_mt(Config) when is_list(Config) ->
     SaNode = ?config(snmp_sa, Config),
@@ -1498,7 +1499,8 @@ mt_trap(Config) when is_list(Config) ->
     ?line load_master("TestTrapv2"),
     try_test(mt_trap_test, [MA]),
     ?line unload_master("TestTrapv2"),
-    ?line unload_master("Test1").
+    ?line unload_master("Test1"),
+    ok.
 
 v2_types(suite) -> [];
 v2_types(Config) when is_list(Config) ->
@@ -3134,8 +3136,9 @@ mt_trap_test(MA) ->
     ?DBG("mt_trap_test(01) -> issue testTrapv22 (standard trap)", []),
     snmpa:send_trap(MA, testTrapv22, "standard trap"),
     ?DBG("mt_trap_test(02) -> await v2trap", []),
-    ?line expect(1, v2trap, [{[sysUpTime, 0], any},
-			     {[snmpTrapOID, 0], ?system ++ [0,1]}]),
+    ?line expect(mt_trap_test_1, v2trap, 
+		 [{[sysUpTime, 0],   any},
+		  {[snmpTrapOID, 0], ?system ++ [0,1]}]),
 
     ?DBG("mt_trap_test(03) -> issue mtTrap (standard trap)", []),
     snmpa:send_trap(MA, mtTrap, "standard trap"),
@@ -3143,28 +3146,22 @@ mt_trap_test(MA) ->
     ?DBG("mt_trap_test(04) -> multi pid: ~p. Now request sysUpTime...", [Pid]),
     g([[sysUpTime,0]]),
 
-    %% Previously (before OTP-6784) this was done at 09 below 
-    %% when the test1:multiStr was actually executed by the 
-    %% worker-process, but as of 4.9.4, this is now executed
-    %% my the master_agent-process...
-    ?DBG("mt_trap_test(05) -> send continue to multi-pid", []),
-    Pid ! continue,
-
     ?DBG("mt_trap_test(06) -> await sysUpTime", []),
-    ?line expect(2, [{[sysUpTime,0], any}]),
+    ?line expect(mt_trap_test_2, [{[sysUpTime,0], any}]),
     ?DBG("mt_trap_test(07) -> issue testTrapv22 (standard trap)", []),
     snmpa:send_trap(MA, testTrapv22, "standard trap"),
     ?DBG("mt_trap_test(08) -> await v2trap", []),
-    ?line expect(3, v2trap, [{[sysUpTime, 0], any},
-			     {[snmpTrapOID, 0], ?system ++ [0,1]}]),
+    ?line expect(mt_trap_test_3, v2trap, 
+		 [{[sysUpTime, 0],   any}, 
+		  {[snmpTrapOID, 0], ?system ++ [0,1]}]),
 
-    %% ?DBG("mt_trap_test(09) -> send continue to multi-pid", []),
-    %% Pid ! continue,
+    ?DBG("mt_trap_test(09) -> send continue to multi-pid", []),
+    Pid ! continue,
 
     ?DBG("mt_trap_test(10) -> await v2trap", []),
-    ?line expect(4, v2trap, [{[sysUpTime, 0], any},
-			     {[snmpTrapOID, 0], ?testTrap ++ [2]},
-			     {[multiStr,0], "ok"}]),
+    ?line expect(mt_trap_test_4, v2trap, [{[sysUpTime, 0], any},
+					  {[snmpTrapOID, 0], ?testTrap ++ [2]},
+					  {[multiStr,0], "ok"}]),
     ?DBG("mt_trap_test(11) -> done", []),
     ok.
 
@@ -3563,53 +3560,82 @@ do_mul_set_err() ->
 %% Req. SA-MIB
 sa_mib() ->
     g([[sa, [2,0]]]),
-    ?line expect(1, [{[sa, [2,0]], 3}]),
+    ?line expect(sa_mib_1, [{[sa, [2,0]], 3}]),
     s([{[sa, [1,0]], s, "sa_test"}]),
-    ?line expect(2, [{[sa, [1,0]], "sa_test"}]).
+    ?line expect(sa_mib_2, [{[sa, [1,0]], "sa_test"}]),
+    ok.
 
 ma_trap1(MA) ->
     ok = snmpa:send_trap(MA, testTrap2, "standard trap"), 
-    ?line expect(1, trap, [system], 6, 1, [{[system, [4,0]],
-				    "{mbj,eklas}@erlang.ericsson.se"}]),
+    ?line expect(ma_trap1_1, 
+		 trap, [system], 6, 1, [{[system, [4,0]],
+					 "{mbj,eklas}@erlang.ericsson.se"}]),
     ok = snmpa:send_trap(MA, testTrap1, "standard trap"),
-    ?line expect(2, trap, [1,2,3] , 1, 0, [{[system, [4,0]],
-				      "{mbj,eklas}@erlang.ericsson.se"}]).
+    ?line expect(ma_trap1_2, 
+		 trap, [1,2,3] , 1, 0, [{[system, [4,0]],
+					 "{mbj,eklas}@erlang.ericsson.se"}]),
+    ok.
 
 ma_trap2(MA) ->
     snmpa:send_trap(MA,testTrap2,"standard trap",[{sysContact,"pelle"}]),
-    ?line expect(3, trap, [system], 6, 1, [{[system, [4,0]], "pelle"}]).
+    ?line expect(ma_trap2_3, 
+		 trap, [system], 6, 1, [{[system, [4,0]], "pelle"}]),
+    ok.
 
 ma_v2_2_v1_trap(MA) ->
     snmpa:send_trap(MA,testTrapv22,"standard trap",[{sysContact,"pelle"}]),
-    ?line expect(3, trap, [system], 6, 1, [{[system, [4,0]], "pelle"}]).    
+    ?line expect(ma_v2_2_v1_trap_3, 
+		 trap, [system], 6, 1, [{[system, [4,0]], "pelle"}]),
+    ok.    
 
 ma_v2_2_v1_trap2(MA) ->
     snmpa:send_trap(MA,linkUp,"standard trap",[{ifIndex, [1], 1},
 					      {ifAdminStatus, [1], 1},
 					      {ifOperStatus, [1], 2}]),
-    ?line expect(3, trap, [1,2,3], 3, 0, [{[ifIndex, 1], 1},
-					 {[ifAdminStatus, 1], 1},
-					 {[ifOperStatus, 1], 2}]).    
+    ?line expect(ma_v2_2_v1_trap2_3, 
+		 trap, [1,2,3], 3, 0, [{[ifIndex, 1], 1},
+				       {[ifAdminStatus, 1], 1},
+				       {[ifOperStatus, 1], 2}]),
+    ok.
 
 sa_trap1(SA) ->
-    snmpa:send_trap(SA, saTrap, "standard trap"),
-    ?line expect(4, trap, [ericsson], 6, 1, [{[system, [4,0]],
-				      "{mbj,eklas}@erlang.ericsson.se"},
-				     {[sa, [1,0]], "sa_test"}]).
+    %% io:format("sa_trap1 -> entry with"
+    %% 	      "~n   SA:       ~p"
+    %% 	      "~n   node(SA): ~p"
+    %% 	      "~n   self():   ~p"
+    %% 	      "~n   node():   ~p"
+    %% 	      "~n", [SA, node(SA), self(), node()]),
+    _VRes  = (catch snmpa:verbosity(SA, {subagents, trace})),
+    %% io:format("sa_trap1 -> SA verbosity set: "
+    %% 	      "~n   VRes: ~p"
+    %% 	      "~n", [VRes]),
+    _TSRes = (catch snmpa:send_trap(SA, saTrap, "standard trap")),
+    %% io:format("sa_trap1 -> SA trap send: "
+    %% 	      "~n   TSRes: ~p"
+    %% 	      "~n", [TSRes]),
+    ?line expect(sa_trap1_4, 
+		 trap, [ericsson], 6, 1, [{[system, [4,0]],
+					   "{mbj,eklas}@erlang.ericsson.se"},
+					  {[sa, [1,0]], "sa_test"}]),
+    snmpa:verbosity(SA, {subagents, silence}),
+    ok.
 
 sa_trap2(SA) ->
     snmpa:send_trap(SA, saTrap, "standard trap",[{sysContact,"pelle"}]),
-    ?line expect(5, trap, [ericsson], 6, 1, [{[system, [4,0]],
-				      "pelle"},
-				     {[sa, [1,0]], "sa_test"}]).
+    ?line expect(sa_trap2_5, 
+		 trap, [ericsson], 6, 1, [{[system, [4,0]], "pelle"},
+					  {[sa, [1,0]], "sa_test"}]),
+    ok.
 
 sa_trap3(SA) ->
     snmpa:send_trap(SA, saTrap2, "standard trap",
 			 [{intViewSubtree, [4], [1,2,3,4]}]),
-    ?line expect(6, trap, [ericsson], 6, 2, [{[system, [4,0]],
-				      "{mbj,eklas}@erlang.ericsson.se"},
-				     {[sa, [1,0]], "sa_test"},
-				     {[intViewSubtree,4],[1,2,3,4]}]).
+    ?line expect(sa_trap3_6, 
+		 trap, [ericsson], 6, 2, [{[system, [4,0]],
+					   "{mbj,eklas}@erlang.ericsson.se"},
+					  {[sa, [1,0]], "sa_test"},
+					  {[intViewSubtree,4],[1,2,3,4]}]),
+    ok.
 
 ma_v2_trap1(MA) ->
     ?DBG("ma_v2_traps -> entry with MA = ~p => "
@@ -4029,33 +4055,42 @@ ma_v1_2_v2_trap2(MA) ->
     
 
 sa_v1_2_v2_trap1(SA) ->
+    snmpa:verbosity(SA, {subagents, trace}),
     snmpa:send_trap(SA, saTrap, "standard trap"),
-    ?line expect(4, v2trap, [{[sysUpTime, 0], any},
-			     {[snmpTrapOID, 0], ?ericsson ++ [0, 1]},
-			     {[system, [4,0]],
-			      "{mbj,eklas}@erlang.ericsson.se"},
-			     {[sa, [1,0]], "sa_test"},
-			     {[snmpTrapEnterprise, 0], ?ericsson}]).
+    ?line expect(trap1_4, v2trap, [{[sysUpTime, 0], any},
+				   {[snmpTrapOID, 0], ?ericsson ++ [0, 1]},
+				   {[system, [4,0]],
+				    "{mbj,eklas}@erlang.ericsson.se"},
+				   {[sa, [1,0]], "sa_test"},
+				   {[snmpTrapEnterprise, 0], ?ericsson}]),
+    snmpa:verbosity(SA, {subagents, silence}),
+    ok.
 
 sa_v1_2_v2_trap2(SA) ->
+    snmpa:verbosity(SA, {subagents, trace}),
     snmpa:send_trap(SA, saTrap, "standard trap",[{sysContact,"pelle"}]),
-    ?line expect(4, v2trap, [{[sysUpTime, 0], any},
-			     {[snmpTrapOID, 0], ?ericsson ++ [0, 1]},
-			     {[system, [4,0]], "pelle"},
-			     {[sa, [1,0]], "sa_test"},
-			     {[snmpTrapEnterprise, 0], ?ericsson}]).
-			     
+    ?line expect(trap2_4, v2trap, [{[sysUpTime, 0], any},
+				   {[snmpTrapOID, 0], ?ericsson ++ [0, 1]},
+				   {[system, [4,0]], "pelle"},
+				   {[sa, [1,0]], "sa_test"},
+				   {[snmpTrapEnterprise, 0], ?ericsson}]),
+    snmpa:verbosity(SA, {subagents, silence}),
+    ok.
+
 
 sa_v1_2_v2_trap3(SA) ->
+    snmpa:verbosity(SA, {subagents, trace}),
     snmpa:send_trap(SA, saTrap2, "standard trap",
 			 [{intViewSubtree, [4], [1,2,3,4]}]),
-    ?line expect(4, v2trap, [{[sysUpTime, 0], any},
-			     {[snmpTrapOID, 0], ?ericsson ++ [0, 2]},
-			     {[system, [4,0]],
-			      "{mbj,eklas}@erlang.ericsson.se"},
-			     {[sa, [1,0]], "sa_test"},
-			     {[intViewSubtree,4],[1,2,3,4]},
-			     {[snmpTrapEnterprise, 0], ?ericsson}]).
+    ?line expect(trap3_4, v2trap, [{[sysUpTime, 0], any},
+				   {[snmpTrapOID, 0], ?ericsson ++ [0, 2]},
+				   {[system, [4,0]],
+				    "{mbj,eklas}@erlang.ericsson.se"},
+				   {[sa, [1,0]], "sa_test"},
+				   {[intViewSubtree,4],[1,2,3,4]},
+				   {[snmpTrapEnterprise, 0], ?ericsson}]),
+    snmpa:verbosity(SA, {subagents, silence}),
+    ok.
 			     
 
 %% Req. SA-MIB, OLD-SNMPEA-MIB
@@ -4195,9 +4230,9 @@ snmp_standard_mib(Config) when is_list(Config) ->
 
 %% Req. SNMP-STANDARD-MIB
 standard_mib_a() ->
-    ?line [OutPkts] = get_req(2, [[snmpOutPkts,0]]),
+    ?line [OutPkts]  = get_req(2, [[snmpOutPkts,0]]),
     ?line [OutPkts2] = get_req(3, [[snmpOutPkts,0]]),
-    ?line OutPkts2 = OutPkts + 1,
+    ?line OutPkts2   = OutPkts + 1,
     %% There are some more counters we could test here, but it's not that
     %% important, since they are removed from SNMPv2-MIB.
     ok.
@@ -4207,27 +4242,27 @@ std_mib_init() ->
     %% disable authentication failure traps.  (otherwise w'd get many of
     %% them - this is also a test to see that it works).
     s([{[snmpEnableAuthenTraps,0], 2}]),
-    ?line expect(1, [{[snmpEnableAuthenTraps, 0], 2}]).
+    ?line expect(std_mib_init_1, [{[snmpEnableAuthenTraps, 0], 2}]).
 
 %% Req. SNMP-STANDARD-MIB | SNMPv2-MIB
 std_mib_finish() ->
     %% enable again
     s([{[snmpEnableAuthenTraps,0], 1}]),
-    ?line expect(1, [{[snmpEnableAuthenTraps, 0], 1}]).
+    ?line expect(std_mib_finish_1, [{[snmpEnableAuthenTraps, 0], 1}]).
 
 %% Req. SNMP-STANDARD-MIB
 standard_mib_test_finish() ->
-    %% force a authenticationFailure
+    %% force a authenticationFailure (should result in a trap)
     std_mib_write(),
     %% check that we got a trap
-    ?line expect(2, trap, [1,2,3], 4, 0, []).
+    ?line expect(standard_mib_test_finish_2, trap, [1,2,3], 4, 0, []).
 
 %% Req. SNMP-STANDARD-MIB | SNMPv2-MIB
 std_mib_read() ->
     ?DBG("std_mib_read -> entry", []),
     g([[sysUpTime,0]]), % try a bad <something>; msg dropped, no reply
     ?DBG("std_mib_read -> await timeout (i.e. no reply)", []),
-    ?line expect(1, timeout). % make sure we don't get a trap!
+    ?line expect(std_mib_read_1, timeout). % make sure we don't get a trap!
 
 
 %% Req. SNMP-STANDARD-MIB | SNMPv2-MIB
@@ -4362,10 +4397,10 @@ std_mib_c({InBadCommunityNames, InBadCommunityUses, InASNErrs}) ->
 snmpv2_mib_a() ->
     ?line [SetSerial] = get_req(2, [[snmpSetSerialNo,0]]),
     s([{[snmpSetSerialNo,0], SetSerial}, {[sysLocation, 0], "val2"}]),
-    ?line expect(3, [{[snmpSetSerialNo,0], SetSerial},
-		     {[sysLocation, 0], "val2"}]),
+    ?line expect(snmpv2_mib_a_3, [{[snmpSetSerialNo,0], SetSerial},
+				  {[sysLocation, 0], "val2"}]),
     s([{[sysLocation, 0], "val3"}, {[snmpSetSerialNo,0], SetSerial}]),
-    ?line expect(4, inconsistentValue, 2,
+    ?line expect(snmpv2_mib_a_4, inconsistentValue, 2,
 		 [{[sysLocation, 0], "val3"},
 		  {[snmpSetSerialNo,0], SetSerial}]),
     ?line ["val2"] = get_req(5, [[sysLocation,0]]).
diff --git a/lib/snmp/test/snmp_agent_test_lib.erl b/lib/snmp/test/snmp_agent_test_lib.erl
index a18d9f3201..084b3ee8da 100644
--- a/lib/snmp/test/snmp_agent_test_lib.erl
+++ b/lib/snmp/test/snmp_agent_test_lib.erl
@@ -296,7 +296,12 @@ call(N,M,F,A) ->
 	    ?DBG("call -> done:"
 		 "~n   Ret: ~p"
 		 "~n   Zed: ~p", [Ret, Zed]),
-	    Ret
+	    case Ret of
+		{error, Reason} ->
+		    exit(Reason);
+		OK ->
+		    OK
+	    end
     end.
 
 wait(From, Env, M, F, A) ->
@@ -724,17 +729,13 @@ expect(Id, A, B, C, D, E) ->
     expect2(Id, Fun).
 
 expect2(Id, F) ->
-    io:format("~w:expect2 -> entry with"
-	      "~n   Id:   ~w"
-	      "~n", [?MODULE, Id]),
+    io:format("EXPECT for ~w~n", [Id]),
     case F() of
 	{error, Reason} ->
-	    {error, Id, Reason};
+	    io:format("EXPECT failed for ~w: ~n~p~n", [Id, Reason]),
+	    throw({error, {expect, Id, Reason}});
 	Else ->
-	    io:format("~w:expect2 -> "
-		      "~n   Id:   ~w"
-		      "~n   Else: ~p"
-		      "~n", [?MODULE, Id, Else]),
+	    io:format("EXPECT result for ~w: ~n~p~n", [Id, Else]),
 	    Else
     end.
 
@@ -769,21 +770,15 @@ do_expect(Expect) when is_atom(Expect) ->
 
 do_expect({any_pdu, To}) 
   when is_integer(To) orelse (To =:= infinity) ->
-    io:format("~w:do_expect(any_pdu) -> entry with"
-	      "~n   To:   ~w"
-	      "~n", [?MODULE, To]),
+    io:format("EXPECT any PDU~n", []),
     receive_pdu(To);
 
 do_expect({any_trap, To}) ->
-    io:format("~w:do_expect(any_trap) -> entry with"
-	      "~n   To:   ~w"
-	      "~n", [?MODULE, To]),
+    io:format("EXPECT any TRAP within ~w~n", [To]),
     receive_trap(To);
 
 do_expect({timeout, To}) ->
-    io:format("~w:do_expect(timeout) -> entry with"
-	      "~n   To:   ~w"
-	      "~n", [?MODULE, To]),
+    io:format("EXPECT nothing within ~w~n", [To]),
     receive
 	X ->
 	    {error, {unexpected, X}}
@@ -794,13 +789,16 @@ do_expect({timeout, To}) ->
 
 do_expect({Err, To}) 
   when is_atom(Err) andalso (is_integer(To) orelse (To =:= infinity)) ->
+    io:format("EXPECT error ~w within ~w~n", [Err, To]),
     do_expect({{error, Err}, To});
 
 do_expect({error, Err}) when is_atom(Err) ->
     Check = fun(_, R) -> R end,
+    io:format("EXPECT error ~w~n", [Err]),
     do_expect2(Check, any, Err, any, any, get_timeout());
 do_expect({{error, Err}, To}) ->
     Check = fun(_, R) -> R end,
+    io:format("EXPECT error ~w within ~w~n", [Err, To]),
     do_expect2(Check, any, Err, any, any, To);
 
 %% exp_varbinds() -> [exp_varbind()]
@@ -810,16 +808,25 @@ do_expect({{error, Err}, To}) ->
 %% ExpVBs         -> exp_varbinds() | {VbsCondition, exp_varbinds()}
 do_expect(ExpVBs) ->
     Check = fun(_, R) -> R end,
+    io:format("EXPECT 'get-response'"
+	      "~n   with"
+	      "~n      Varbinds: ~p~n", [ExpVBs]),
     do_expect2(Check, 'get-response', noError, 0, ExpVBs, get_timeout()).
 
 
 do_expect(v2trap, ExpVBs) ->
     Check = fun(_, R) -> R end,
+    io:format("EXPECT 'snmpv2-trap'"
+	      "~n   with"
+	      "~n      Varbinds: ~p~n", [ExpVBs]),
     do_expect2(Check, 'snmpv2-trap', noError, 0, ExpVBs, get_timeout());
 
 
 do_expect(report, ExpVBs) ->
     Check = fun(_, R) -> R end,
+    io:format("EXPECT 'report'"
+	      "~n   with"
+	      "~n      Varbinds: ~p~n", [ExpVBs]),
     do_expect2(Check, 'report', noError, 0, ExpVBs, get_timeout());
 
 
@@ -827,16 +834,13 @@ do_expect(inform, ExpVBs) ->
     do_expect({inform, true}, ExpVBs);
 
 do_expect({inform, false}, ExpVBs) ->
-    io:format("~w:do_expect(inform, false) -> entry with"
-	      "~n   ExpVBs: ~p"
-	      "~n", [?MODULE, ExpVBs]),
     Check = fun(_, R) -> R end,
+    io:format("EXPECT 'inform-request' (false)"
+	      "~n   with"
+	      "~n      Varbinds: ~p~n", [ExpVBs]),
     do_expect2(Check, 'inform-request', noError, 0, ExpVBs, get_timeout());
 
 do_expect({inform, true}, ExpVBs) ->
-    io:format("~w:do_expect(inform, true) -> entry with"
-	      "~n   ExpVBs: ~p"
-	      "~n", [?MODULE, ExpVBs]),
     Check = 
 	fun(PDU, ok) ->
 		RespPDU = PDU#pdu{type         = 'get-response',
@@ -847,6 +851,9 @@ do_expect({inform, true}, ExpVBs) ->
 	   (_, Err) ->
 		Err
 	end,
+    io:format("EXPECT 'inform-request' (true)"
+	      "~n   with"
+	      "~n      Varbinds: ~p~n", [ExpVBs]),
     do_expect2(Check, 'inform-request', noError, 0, ExpVBs, get_timeout());
 
 do_expect({inform, {error, EStat, EIdx}}, ExpVBs) 
@@ -861,6 +868,11 @@ do_expect({inform, {error, EStat, EIdx}}, ExpVBs)
 	   (_, Err) ->
 		Err
 	end,
+    io:format("EXPECT 'inform-request' (error)"
+	      "~n   with"
+	      "~n      Error Status: ~p"
+	      "~n      Error Index:  ~p"
+	      "~n      Varbinds:     ~p~n", [EStat, EIdx, ExpVBs]),
     do_expect2(Check, 'inform-request', noError, 0, ExpVBs, get_timeout()).
 
 
@@ -871,6 +883,12 @@ do_expect(Err, Idx, ExpVBs, To)
   when is_atom(Err) andalso 
        (is_integer(Idx) orelse is_list(Idx) orelse (Idx == any)) ->
     Check = fun(_, R) -> R end,
+    io:format("EXPECT 'get-response'"
+	      "~n   with"
+	      "~n      Error:    ~p"
+	      "~n      Index:    ~p"
+	      "~n      Varbinds: ~p"
+	      "~n   within ~w~n", [Err, Idx, ExpVBs, To]),
     do_expect2(Check, 'get-response', Err, Idx, ExpVBs, To).
 
 
@@ -878,15 +896,13 @@ do_expect(Type, Enterp, Generic, Specific, ExpVBs) ->
     do_expect(Type, Enterp, Generic, Specific, ExpVBs, 3500).
 
 do_expect(trap, Enterp, Generic, Specific, ExpVBs, To) ->
-    io:format("~w:do_expect(trap) -> entry with"
-	      "~n   Enterp:   ~w"
-	      "~n   Generic:  ~w"
-	      "~n   Specific: ~w"
-	      "~n   ExpVBs:   ~w"
-	      "~n   To:       ~w"
-	      "~nwhen"
-	      "~n   Time:   ~w"
-	      "~n", [?MODULE, Enterp, Generic, Specific, ExpVBs, To, t()]),
+    io:format("EXPECT trap"
+	      "~n   with"
+	      "~n      Enterp:   ~w"
+	      "~n      Generic:  ~w"
+	      "~n      Specific: ~w"
+	      "~n      Varbinds: ~w"
+	      "~n   within ~w~n", [Enterp, Generic, Specific, ExpVBs, To]),
     PureE = purify_oid(Enterp),
     case receive_trap(To) of
 	#trappdu{enterprise    = PureE, 
@@ -916,49 +932,51 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To)
        (is_list(ExpVBs) orelse (ExpVBs =:= any)) andalso
        (is_integer(To) orelse (To =:= infinity)) ->
 
-    io:format("~w:do_expect2 -> entry with"
-	      "~n   Type:   ~w"
-	      "~n   Err:    ~w"
-	      "~n   Idx:    ~w"
-	      "~n   ExpVBs: ~w"
-	      "~n   To:     ~w"
-	      "~nwhen"
-	      "~n   Time:   ~w"
-	      "~n", [?MODULE, Type, Err, Idx, ExpVBs, To, t()]),
-
     case receive_pdu(To) of
 
 	#pdu{type         = Type, 
 	     error_status = Err,
 	     error_index  = Idx} when ExpVBs =:= any -> 
+	    io:format("EXPECT received expected pdu (1)~n", []),
 	    ok;
 
 	#pdu{type         = Type, 
 	     request_id   = ReqId, 
 	     error_status = Err2,
 	     error_index  = Idx} when ExpVBs =:= any -> 
+	    io:format("EXPECT received expected pdu with "
+		      "unexpected error status (2): "
+		      "~n   Error Status: ~p~n", [Err2]),
 	    {error, {unexpected_error_status, Err, Err2, ReqId}};
 
 	#pdu{error_status = Err} when (Type   =:= any) andalso 
 				      (Idx    =:= any) andalso 
 				      (ExpVBs =:= any) -> 
+	    io:format("EXPECT received expected pdu (3)~n", []),
 	    ok;
 
 	#pdu{request_id   = ReqId, 
 	     error_status = Err2} when (Type   =:= any) andalso 
 				       (Idx    =:= any) andalso 
 				       (ExpVBs =:= any) -> 
+	    io:format("EXPECT received expected pdu with "
+		      "unexpected error status (4): "
+		      "~n   Error Status: ~p~n", [Err2]),
 	    {error, {unexpected_error_status, Err, Err2, ReqId}};
 
 	#pdu{type         = Type, 
 	     error_status = Err} when (Idx =:= any) andalso 
 				      (ExpVBs =:= any) -> 
+	    io:format("EXPECT received expected pdu (5)~n", []),
 	    ok;
 
 	#pdu{type         = Type, 
 	     request_id   = ReqId, 
 	     error_status = Err2} when (Idx =:= any) andalso 
 				       (ExpVBs =:= any) -> 
+	    io:format("EXPECT received expected pdu with "
+		      "unexpected error status (6): "
+		      "~n   Error Status: ~p~n", [Err2]),
 	    {error, {unexpected_error_status, Err, Err2, ReqId}};
 
 	#pdu{type         = Type, 
@@ -967,8 +985,13 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To)
 	     error_index  = EI} when is_list(Idx) andalso (ExpVBs =:= any) -> 
 	    case lists:member(EI, Idx) of
 		true ->
+		    io:format("EXPECT received expected pdu with "
+			      "expected error index (7)~n", []),
 		    ok;
 		false ->
+		    io:format("EXPECT received expected pdu with "
+			      "unexpected error index (8): "
+			      "~n   Error Index: ~p~n", [EI]),
 		    {error, {unexpected_error_index, EI, Idx, ReqId}}
 	    end;
 
@@ -978,8 +1001,15 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To)
 	     error_index  = EI} when is_list(Idx) andalso (ExpVBs =:= any) -> 
 	    case lists:member(EI, Idx) of
 		true ->
+		    io:format("EXPECT received expected pdu with "
+			      "unexpected error status (9): "
+			      "~n   Error Status: ~p~n", [Err2]),
 		    {error, {unexpected_error_status, Err, Err2, ReqId}};
 		false ->
+		    io:format("EXPECT received expected pdu with "
+			      "unexpected error (10): "
+			      "~n   Error Status: ~p"
+			      "~n   Error index:  ~p~n", [Err2, EI]),
 		    {error, {unexpected_error, {Err, Idx}, {Err2, EI}, ReqId}}
 	    end;
 
@@ -987,6 +1017,12 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To)
 	     request_id   = ReqId, 
 	     error_status = Err2, 
 	     error_index  = Idx2} when ExpVBs =:= any ->
+	    io:format("EXPECT received unexpected pdu with (11) "
+		      "~n   Type:         ~p"
+		      "~n   ReqId:        ~p"
+		      "~n   Errot status: ~p"
+		      "~n   Error index:  ~p"
+		      "~n", [Type2, ReqId, Err2, Idx2]),
 	    {error, 
 	     {unexpected_pdu, 
 	      {Type, Err, Idx}, {Type2, Err2, Idx2}, ReqId}};
@@ -995,11 +1031,26 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To)
 	     error_status = Err, 
 	     error_index  = Idx,
 	     varbinds     = VBs} = PDU ->
+	    io:format("EXPECT received pdu (12): "
+		      "~n   [exp] Type:         ~p"
+		      "~n   [exp] Error Status: ~p"
+		      "~n   [exp] Error Index:  ~p"
+		      "~n   VBs:                ~p"
+		      "~nwhen"
+		      "~n   ExpVBs:             ~p"
+		      "~n", [Type, Err, Idx, VBs, ExpVBs]),
 	    Check(PDU, check_vbs(purify_oids(ExpVBs), VBs));
 
 	#pdu{type         = Type, 
 	     error_status = Err, 
 	     varbinds     = VBs} = PDU when Idx =:= any ->
+	    io:format("EXPECT received pdu (13): "
+		      "~n   [exp] Type:         ~p"
+		      "~n   [exp] Error Status: ~p"
+		      "~n   VBs:                ~p"
+		      "~nwhen"
+		      "~n   ExpVBs:             ~p"
+		      "~n", [Type, Err, VBs, ExpVBs]),
 	    Check(PDU, check_vbs(purify_oids(ExpVBs), VBs));
 
 	#pdu{type         = Type, 
@@ -1007,6 +1058,15 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To)
 	     error_status = Err, 
 	     error_index  = EI,
 	     varbinds     = VBs} = PDU when is_list(Idx) ->
+	    io:format("EXPECT received pdu (14): "
+		      "~n   [exp] Type:         ~p"
+		      "~n   ReqId:              ~p"
+		      "~n   [exp] Error Status: ~p"
+		      "~n   [exp] Error Index:  ~p"
+		      "~n   VBs:                ~p"
+		      "~nwhen"
+		      "~n   ExpVBs:             ~p"
+		      "~n", [Type, ReqId, Err, EI, VBs, ExpVBs]),
 	    PureVBs = purify_oids(ExpVBs), 
 	    case lists:member(EI, Idx) of
 		true ->
@@ -1020,6 +1080,13 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To)
 	     error_status = Err2, 
 	     error_index  = Idx2,
 	     varbinds     = VBs2} ->
+	    io:format("EXPECT received unexpected pdu with (15) "
+		      "~n   Type:         ~p"
+		      "~n   ReqId:        ~p"
+		      "~n   Errot status: ~p"
+		      "~n   Error index:  ~p"
+		      "~n   Varbinds:     ~p"
+		      "~n", [Type2, ReqId, Err2, Idx2, VBs2]),
 	    {error, 
 	     {unexpected_pdu, 
 	      {Type,  Err,  Idx, purify_oids(ExpVBs)}, 
@@ -1027,6 +1094,9 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To)
 	      ReqId}};
 	
 	Error ->
+	    io:format("EXPECT received error (16):  "
+		      "~n   Error: ~p"
+		      "~n", [Error]),
 	    Error
     end.
 
@@ -1466,7 +1536,7 @@ rpc(Node, F, A) ->
 %% 
 %% 
 %% t() ->
-%%     {A,B,C} = erlang:now(),
+%%     {A,B,C} = os:timestamp(),
 %%     A*1000000000+B*1000+(C div 1000).
 %% 
 %% 
@@ -1478,6 +1548,6 @@ rpc(Node, F, A) ->
     
 
 %% Time in milli seconds
-t() ->
-    {A,B,C} = erlang:now(),
-    A*1000000000+B*1000+(C div 1000).
+%% t() ->
+%%     {A,B,C} = os:timestamp(),
+%%     A*1000000000+B*1000+(C div 1000).
diff --git a/lib/snmp/vsn.mk b/lib/snmp/vsn.mk
index 0819ab9b36..25e3a9470b 100644
--- a/lib/snmp/vsn.mk
+++ b/lib/snmp/vsn.mk
@@ -17,6 +17,6 @@
 #
 # %CopyrightEnd%
 
-SNMP_VSN = 4.21.2
+SNMP_VSN = 4.21.3
 PRE_VSN  =
 APP_VSN  = "snmp-$(SNMP_VSN)$(PRE_VSN)"