From 2d9d8b868e8a816b8baf08b65035c1e274f3e5b2 Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Mon, 1 Apr 2019 18:13:59 +0200 Subject: [snmp|agent|test] Some minor tweaking of (agent) test suite Improved the test manager printouts to make it easier to diagnose problems... --- lib/snmp/test/snmp_agent_test.erl | 18 +++++++++--------- lib/snmp/test/snmp_test_mgr_misc.erl | 18 ++++++++++-------- 2 files changed, 19 insertions(+), 17 deletions(-) (limited to 'lib') diff --git a/lib/snmp/test/snmp_agent_test.erl b/lib/snmp/test/snmp_agent_test.erl index f9c18af6ea..b71614ed51 100644 --- a/lib/snmp/test/snmp_agent_test.erl +++ b/lib/snmp/test/snmp_agent_test.erl @@ -1116,15 +1116,15 @@ init_ms(Config, Opts) when is_list(Config) -> Opts1 = [MasterAgentVerbosity, MibsVerbosity, SymStoreVerbosity | Opts], [{vsn, v1} | start_v1_agent(Config, Opts1)]. -init_size_check_mse(Config) when is_list(Config) -> - MibStorage = {mib_storage, [{module, snmpa_mib_storage_ets}]}, - init_size_check_ms(Config, [MibStorage]). - -init_size_check_msd(Config) when is_list(Config) -> - AgentDbDir = ?GCONF(agent_db_dir, Config), - MibStorage = {mib_storage, [{module, snmpa_mib_storage_dets}, - {options, [{dir, AgentDbDir}]}]}, - init_size_check_ms(Config, [MibStorage]). +%% init_size_check_mse(Config) when is_list(Config) -> +%% MibStorage = {mib_storage, [{module, snmpa_mib_storage_ets}]}, +%% init_size_check_ms(Config, [MibStorage]). + +%% init_size_check_msd(Config) when is_list(Config) -> +%% AgentDbDir = ?GCONF(agent_db_dir, Config), +%% MibStorage = {mib_storage, [{module, snmpa_mib_storage_dets}, +%% {options, [{dir, AgentDbDir}]}]}, +%% init_size_check_ms(Config, [MibStorage]). init_size_check_msm(Config) when is_list(Config) -> ?line AgentNode = ?GCONF(snmp_master, Config), diff --git a/lib/snmp/test/snmp_test_mgr_misc.erl b/lib/snmp/test/snmp_test_mgr_misc.erl index 274fb5be26..f3f97b5ac4 100644 --- a/lib/snmp/test/snmp_test_mgr_misc.erl +++ b/lib/snmp/test/snmp_test_mgr_misc.erl @@ -211,12 +211,14 @@ handle_udp_packet(_V, undefined, case SnmpMgr of {pdu, Pid} -> Pdu = get_pdu(Msg), - d("packet_loop -> " - "send pdu to manager (~w): ~p", [Pid, Pdu]), + d("handle_udp_packet -> " + "send pdu(v3) to manager (~w): " + "~n ~p", [Pid, Pdu]), Pid ! {snmp_pdu, Pdu}; {msg, Pid} -> d("packet_loop -> " - "send msg to manager (~w): ~p", [Pid, Msg]), + "send msg(v3) to manager (~p): " + "~n ~p", [Pid, Msg]), Pid ! {snmp_msg, Msg, Ip, UdpPort} end, MsgData2; @@ -247,8 +249,8 @@ handle_udp_packet(_V, undefined, Pid ! {snmp_pdu, Pdu}; {msg, Pid} -> d("handle_udp_packet -> " - "send pdu-msg to manager (~w): ~p", - [Pid, Pdu]), + "send msg to manager (~p): " + "~n ~p", [Pid, Pdu]), Msg = Message#message{data = Pdu}, Pid ! {snmp_msg, Msg, Ip, UdpPort} end; @@ -256,13 +258,13 @@ handle_udp_packet(_V, undefined, case SnmpMgr of {pdu, Pid} -> d("handle_udp_packet -> " - "send trap to manager (~w): ~p", + "send trap-pdu to manager (~w): ~p", [Pid, Pdu]), Pid ! {snmp_pdu, Pdu}; {msg, Pid} -> d("handle_udp_packet -> " - "send trap-msg to manager (~w): ~p", - [Pid, Pdu]), + "send trap-msg to manager (~w): " + "~n ~p", [Pid, Pdu]), Msg = Message#message{data = Pdu}, Pid ! {snmp_msg, Msg, Ip, UdpPort} end; -- cgit v1.2.3 From 7df6b64bd58b517684b39e090f220d7154eeb1a0 Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Tue, 2 Apr 2019 12:44:28 +0200 Subject: [snmp|agent|test] Tweaked the (agent) test manager The test manager used in the agent tests has been tweaked in order to increase the readability (both of the code and the output). --- lib/snmp/test/snmp_test_mgr_misc.erl | 182 +++++++++++++++++++---------------- 1 file changed, 100 insertions(+), 82 deletions(-) (limited to 'lib') diff --git a/lib/snmp/test/snmp_test_mgr_misc.erl b/lib/snmp/test/snmp_test_mgr_misc.erl index f3f97b5ac4..9e76452345 100644 --- a/lib/snmp/test/snmp_test_mgr_misc.erl +++ b/lib/snmp/test/snmp_test_mgr_misc.erl @@ -200,88 +200,24 @@ packet_loop(SnmpMgr, UdpId, AgentIp, UdpPort, VsnHdr, Version, MsgData) -> handle_udp_packet(_V, undefined, UdpId, Ip, UdpPort, Bytes, SnmpMgr, AgentIp) -> - M = (catch snmp_pdus:dec_message_only(Bytes)), - MsgData3 = - case M of - Message when Message#message.version =:= 'version-3' -> - d("handle_udp_packet -> version 3"), - case catch handle_v3_msg(Bytes, Message) of - {ok, NewData, MsgData2} -> - Msg = Message#message{data = NewData}, - case SnmpMgr of - {pdu, Pid} -> - Pdu = get_pdu(Msg), - d("handle_udp_packet -> " - "send pdu(v3) to manager (~w): " - "~n ~p", [Pid, Pdu]), - Pid ! {snmp_pdu, Pdu}; - {msg, Pid} -> - d("packet_loop -> " - "send msg(v3) to manager (~p): " - "~n ~p", [Pid, Msg]), - Pid ! {snmp_msg, Msg, Ip, UdpPort} - end, - MsgData2; - {error, Reason, B} -> - udp_send(UdpId, AgentIp, UdpPort, B), - error("Decoding error. Auto-sending Report.\n" - "Reason: ~w " - "(UDPport: ~w, Ip: ~w)", - [Reason, UdpPort, Ip]), - []; - {error, Reason} -> - error("Decoding error. " - "Bytes: ~w ~n Reason: ~w " - "(UDPport: ~w, Ip: ~w)", - [Bytes, Reason, UdpPort, Ip]), - [] - end; - Message when is_record(Message, message) -> - %% v1 or v2c - d("handle_udp_packet -> version v1 or v2c"), - case catch snmp_pdus:dec_pdu(Message#message.data) of - Pdu when is_record(Pdu, pdu) -> - case SnmpMgr of - {pdu, Pid} -> - d("handle_udp_packet -> " - "send pdu to manager (~w): ~p", - [Pid, Pdu]), - Pid ! {snmp_pdu, Pdu}; - {msg, Pid} -> - d("handle_udp_packet -> " - "send msg to manager (~p): " - "~n ~p", [Pid, Pdu]), - Msg = Message#message{data = Pdu}, - Pid ! {snmp_msg, Msg, Ip, UdpPort} - end; - Pdu when is_record(Pdu, trappdu) -> - case SnmpMgr of - {pdu, Pid} -> - d("handle_udp_packet -> " - "send trap-pdu to manager (~w): ~p", - [Pid, Pdu]), - Pid ! {snmp_pdu, Pdu}; - {msg, Pid} -> - d("handle_udp_packet -> " - "send trap-msg to manager (~w): " - "~n ~p", [Pid, Pdu]), - Msg = Message#message{data = Pdu}, - Pid ! {snmp_msg, Msg, Ip, UdpPort} - end; - Reason -> - error("Decoding error. " - "Bytes: ~w ~n Reason: ~w " - "(UDPport: ~w, Ip: ~w)", - [Bytes, Reason, UdpPort, Ip]) - end, - []; - Reason -> - error("Decoding error. Bytes: ~w ~n Reason: ~w " - "(UDPport: ~w, Ip: ~w)", - [Bytes, Reason, UdpPort, Ip]), - [] - end, - MsgData3; + try snmp_pdus:dec_message_only(Bytes) of + Message when Message#message.version =:= 'version-3' -> + d("handle_udp_packet -> version 3"), + handle_v3_message(SnmpMgr, UdpId, Ip, UdpPort, AgentIp, + Bytes, Message); + + Message when is_record(Message, message) -> + d("handle_udp_packet -> version 1 or 2"), + handle_v1_or_v2_message(SnmpMgr, UdpId, Ip, UdpPort, AgentIp, + Bytes, Message) + + catch + Class:Error:_ -> + error("Decoding error (~w). Bytes: ~w ~n Error: ~w " + "(UDPport: ~w, Ip: ~w)", + [Class, Bytes, Error, UdpPort, Ip]), + [] + end; handle_udp_packet(V, {DiscoReqMsg, From}, _UdpId, _Ip, _UdpPort, Bytes, _, _AgentIp) -> DiscoRspMsg = (catch snmp_pdus:dec_message(Bytes)), @@ -299,6 +235,88 @@ handle_udp_packet(V, {DiscoReqMsg, From}, _UdpId, _Ip, _UdpPort, [] end. +handle_v3_message(Mgr, UdpId, Ip, UdpPort, AgentIp, + Bytes, Message) -> + try handle_v3_msg(Bytes, Message) of + {ok, NewData, MsgData} -> + Msg = Message#message{data = NewData}, + case Mgr of + {pdu, Pid} -> + Pdu = get_pdu(Msg), + d("handle_v3_message -> send pdu to manager (~p): " + "~n ~p", [Pid, Pdu]), + Pid ! {snmp_pdu, Pdu}; + {msg, Pid} -> + d("handle_v3_message -> send msg to manager (~p): " + "~n ~p", [Pid, Msg]), + Pid ! {snmp_msg, Msg, Ip, UdpPort} + end, + MsgData + + catch + throw:{error, Reason, B}:_ -> + udp_send(UdpId, AgentIp, UdpPort, B), + error("Decoding (v3) error. Auto-sending Report.\n" + "~n Reason: ~w " + "(UDPport: ~w, Ip: ~w)", + [Reason, UdpPort, Ip]), + []; + + throw:{error, Reason}:_ -> + error("Decoding (v3) error. " + "~n Bytes: ~w" + "~n Reason: ~w " + "(UDPport: ~w, Ip: ~w)", + [Bytes, Reason, UdpPort, Ip]), + []; + + Class:Error:_ -> + error("Decoding (v3) error (~w). " + "~n Bytes: ~w" + "~n Error: ~w " + "(UDPport: ~w, Ip: ~w)", + [Class, Bytes, Error, UdpPort, Ip]), + [] + + end. + +handle_v1_or_v2_message(Mgr, _UdpId, Ip, UdpPort, _AgentIp, + Bytes, Message) -> + try snmp_pdus:dec_pdu(Message#message.data) of + Pdu when is_record(Pdu, pdu) -> + case Mgr of + {pdu, Pid} -> + d("handle_v1_or_v2_message -> send pdu to manager (~p): " + "~n ~p", [Pid, Pdu]), + Pid ! {snmp_pdu, Pdu}; + {msg, Pid} -> + d("handle_v1_or_v2_message -> send msg to manager (~p): " + "~n ~p", [Pid, Pdu]), + Msg = Message#message{data = Pdu}, + Pid ! {snmp_msg, Msg, Ip, UdpPort} + end; + Pdu when is_record(Pdu, trappdu) -> + case Mgr of + {pdu, Pid} -> + d("handle_v1_or_v2_message -> send trap-pdu to manager (~p): " + "~n ~p", [Pid, Pdu]), + Pid ! {snmp_pdu, Pdu}; + {msg, Pid} -> + d("handle_v1_or_v2_message -> send trap-msg to manager (~p): " + "~n ~p", [Pid, Pdu]), + Msg = Message#message{data = Pdu}, + Pid ! {snmp_msg, Msg, Ip, UdpPort} + end + + catch + Class:Error:_ -> + error("Decoding (v1 or v2) error (~w): " + "~n Bytes: ~w" + "~n Error: ~w " + "(UDPport: ~w, Ip: ~w)", + [Class, Bytes, Error, UdpPort, Ip]) + end. + %% This function assumes that the agent and the manager (thats us) %% has the same version. -- cgit v1.2.3 From d6c0f9b60786779a274afab2d189d58328ae11ee Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Wed, 3 Apr 2019 12:49:59 +0200 Subject: [snmp|agent] Improved debug printouts Improve debug (verbose) printouts when a get/get-next/get-bulk/set request fails (first by printing at level log instead of trace and secondly by also printing the original operation result when the operation fails). --- lib/snmp/src/agent/snmpa_agent.erl | 117 ++++++++++++++++++++++++------------- 1 file changed, 76 insertions(+), 41 deletions(-) (limited to 'lib') diff --git a/lib/snmp/src/agent/snmpa_agent.erl b/lib/snmp/src/agent/snmpa_agent.erl index a521b3773b..2225a40996 100644 --- a/lib/snmp/src/agent/snmpa_agent.erl +++ b/lib/snmp/src/agent/snmpa_agent.erl @@ -1794,9 +1794,8 @@ worker_loop(Master) -> GbMaxVBs, Extra) end catch - T:E -> - exit({worker_crash, Req, T, E, - erlang:get_stacktrace()}) + C:E:S -> + exit({worker_crash, Req, C, E, S}) end, Master ! worker_available, HandlePduRes; % For debugging... @@ -1822,9 +1821,8 @@ worker_loop(Master) -> get(net_if)) end catch - T:E -> - exit({worker_crash, Req, T, E, - erlang:get_stacktrace()}) + C:E:S -> + exit({worker_crash, Req, C, E, S}) end, Master ! worker_available, SendTrapRes; % For debugging... @@ -2543,22 +2541,31 @@ process_msg( process_pdu(#pdu{type='get-request', request_id = ReqId, varbinds=Vbs}, _PduMS, Vsn, MibView, _GbMaxVBs) -> ?vtrace("get ~p",[ReqId]), - Res = get_err(do_get(MibView, Vbs, false)), - ?vtrace("get result: " - "~n ~p",[Res]), + OrigRes = do_get(MibView, Vbs, false), + Res = get_err(OrigRes), {ErrStatus, ErrIndex, ResVarbinds} = if Vsn =:= 'version-1' -> validate_get_v1(Res); true -> Res end, - ?vtrace("get final result: " - "~n Error status: ~p" - "~n Error index: ~p" - "~n Varbinds: ~p", - [ErrStatus,ErrIndex,ResVarbinds]), + if + (ErrStatus =/= noError) -> + ?vlog("get final result: " + "~n Error status: ~p" + "~n Error index: ~p" + "~n when" + "~n Original Result: " + "~n ~p", [ErrStatus, ErrIndex, OrigRes]); + true -> + ?vtrace("get final result: " + "~n Error status: ~p" + "~n Error index: ~p" + "~n Varbinds: ~p", + [ErrStatus, ErrIndex, ResVarbinds]) + end, ResponseVarbinds = lists:keysort(#varbind.org_index, ResVarbinds), ?vtrace("response varbinds: " - "~n ~p",[ResponseVarbinds]), + "~n ~p", [ResponseVarbinds]), make_response_pdu(ReqId, ErrStatus, ErrIndex, Vbs, ResponseVarbinds); process_pdu(#pdu{type = 'get-next-request', request_id = ReqId, varbinds = Vbs}, @@ -2566,22 +2573,31 @@ process_pdu(#pdu{type = 'get-next-request', request_id = ReqId, varbinds = Vbs}, ?vtrace("process get-next-request -> entry with" "~n ReqId: ~p" "~n Vbs: ~p" - "~n MibView: ~p",[ReqId, Vbs, MibView]), - Res = get_err(do_get_next(MibView, Vbs)), - ?vtrace("get-next result: " - "~n ~p",[Res]), + "~n MibView: ~p", [ReqId, Vbs, MibView]), + OrigRes = do_get_next(MibView, Vbs, infinity), + Res = get_err(OrigRes), {ErrStatus, ErrIndex, ResVarbinds} = if Vsn =:= 'version-1' -> validate_next_v1(Res, MibView); true -> Res end, - ?vtrace("get-next final result -> validation result:" - "~n Error status: ~p" - "~n Error index: ~p" - "~n Varbinds: ~p",[ErrStatus,ErrIndex,ResVarbinds]), + if + (ErrStatus =/= noError) -> + ?vlog("get-next final result: " + "~n Error status: ~p" + "~n Error index: ~p" + "~n when" + "~n Original Result: " + "~n ~p", [ErrStatus, ErrIndex, OrigRes]); + true -> + ?vtrace("get-next final result:" + "~n Error status: ~p" + "~n Error index: ~p" + "~n Varbinds: ~p", [ErrStatus, ErrIndex, ResVarbinds]) + end, ResponseVarbinds = lists:keysort(#varbind.org_index, ResVarbinds), ?vtrace("get-next final result -> response varbinds: " - "~n ~p",[ResponseVarbinds]), + "~n ~p", [ResponseVarbinds]), make_response_pdu(ReqId, ErrStatus, ErrIndex, Vbs, ResponseVarbinds); process_pdu(#pdu{type = 'get-bulk-request', @@ -2590,31 +2606,50 @@ process_pdu(#pdu{type = 'get-bulk-request', error_status = NonRepeaters, error_index = MaxRepetitions}, PduMS, _Vsn, MibView, GbMaxVBs) -> - {ErrStatus, ErrIndex, ResponseVarbinds} = - get_err(do_get_bulk(MibView, NonRepeaters, MaxRepetitions, PduMS, Vbs, - GbMaxVBs)), - ?vtrace("get-bulk final result: " - "~n Error status: ~p" - "~n Error index: ~p" - "~n Respons varbinds: ~p", - [ErrStatus,ErrIndex,ResponseVarbinds]), + OrigRes = do_get_bulk(MibView, NonRepeaters, MaxRepetitions, PduMS, Vbs, + GbMaxVBs), + {ErrStatus, ErrIndex, ResponseVarbinds} = get_err(OrigRes), + if + (ErrStatus =/= noError) -> + ?vlog("get-bulk final result: " + "~n Error Status: ~p" + "~n Error Index: ~p" + "~n when" + "~n Original Result: " + "~n ~p", [ErrStatus, ErrIndex, OrigRes]); + true -> + ?vtrace("get-bulk final result: " + "~n Error status: ~p" + "~n Error index: ~p" + "~n Response Varbinds: ~p", + [ErrStatus, ErrIndex, ResponseVarbinds]) + end, make_response_pdu(ReqId, ErrStatus, ErrIndex, Vbs, ResponseVarbinds); process_pdu(#pdu{type = 'set-request', request_id = ReqId, varbinds = Vbs}, - _PduMS, Vsn, MibView, _GbMaxVbs)-> - Res = do_set(MibView, Vbs), - ?vtrace("set result: " - "~n ~p",[Res]), + _PduMS, Vsn, MibView, _GbMaxVbs) -> + OrigRes = do_set(MibView, Vbs), {ErrStatus, ErrIndex} = if - Vsn =:= 'version-1' -> validate_err(v2_to_v1, Res); - true -> Res + Vsn =:= 'version-1' -> validate_err(v2_to_v1, OrigRes); + true -> OrigRes end, - ?vtrace("set final result: " - "~n Error status: ~p" - "~n Error index: ~p",[ErrStatus,ErrIndex]), + if + (ErrStatus =/= noError) -> + ?vlog("set final result: " + "~n Error Status: ~p" + "~n Error Index: ~p" + "~n when" + "~n Original Result: " + "~n ~p", [ErrStatus, ErrIndex, OrigRes]); + true -> + ?vtrace("set final result: " + "~n Error Status: ~p" + "~n Error Index: ~p", [ErrStatus, ErrIndex]) + end, make_response_pdu(ReqId, ErrStatus, ErrIndex, Vbs, Vbs). + %%----------------------------------------------------------------- %% Transform a value == noSuchInstance | noSuchObject or a %% Counter64 type to a noSuchName error for the whole pdu. -- cgit v1.2.3 From e7c9ded977218db7fa19c3fcc5169be08c4e7010 Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Wed, 3 Apr 2019 12:52:42 +0200 Subject: [snmp|agent|test] Improve the EXPECT printouts The EXPECT printouts has been improved. Partly by including a timestamp. --- lib/snmp/test/snmp_agent_test_lib.erl | 214 +++++++++++++++++----------------- 1 file changed, 107 insertions(+), 107 deletions(-) (limited to 'lib') diff --git a/lib/snmp/test/snmp_agent_test_lib.erl b/lib/snmp/test/snmp_agent_test_lib.erl index c19c88528f..8749df0c3f 100644 --- a/lib/snmp/test/snmp_agent_test_lib.erl +++ b/lib/snmp/test/snmp_agent_test_lib.erl @@ -864,13 +864,15 @@ expect(Mod, Line, Type, Enterp, Generic, Specific, ExpVBs) -> expect2(Mod, Line, Fun). expect2(Mod, Line, F) -> - io:format("EXPECT for ~w:~w~n", [Mod, Line]), + io_format_expect("for ~w:~w", [Mod, Line]), case F() of {error, Reason} -> - io:format("EXPECT failed at ~w:~w => ~n~p~n", [Mod, Line, Reason]), + io_format_expect("failed at ~w:~w => " + "~n ~p", [Mod, Line, Reason]), throw({error, {expect, Mod, Line, Reason}}); Else -> - io:format("EXPECT result for ~w:~w => ~n~p~n", [Mod, Line, Else]), + io_format_expect("result for ~w:~w => " + "~n ~p", [Mod, Line, Else]), Else end. @@ -899,20 +901,27 @@ receive_trap(To) -> end. +io_format_expect(F) -> + io_format_expect(F, []). + +io_format_expect(F, A) -> + FTS = snmp_test_lib:formated_timestamp(), + io:format("[~s] EXPECT " ++ F ++ "~n", [FTS | A]). + do_expect(Expect) when is_atom(Expect) -> do_expect({Expect, get_timeout()}); do_expect({any_pdu, To}) when is_integer(To) orelse (To =:= infinity) -> - io:format("EXPECT any PDU~n", []), + io_format_expect("any PDU"), receive_pdu(To); do_expect({any_trap, To}) -> - io:format("EXPECT any TRAP within ~w~n", [To]), + io_format_expect("any TRAP within ~w", [To]), receive_trap(To); do_expect({timeout, To}) -> - io:format("EXPECT nothing within ~w~n", [To]), + io_format_expect("nothing within ~w", [To]), receive X -> {error, {unexpected, X}} @@ -924,16 +933,16 @@ do_expect({timeout, To}) -> do_expect({Err, To}) when (is_atom(Err) andalso ((is_integer(To) andalso To > 0) orelse (To =:= infinity))) -> - io:format("EXPECT error ~w within ~w~n", [Err, To]), + io_format_expect("error ~w within ~w", [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]), + io_format_expect("error ~w", [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]), + io_format_expect("error ~w within ~w", [Err, To]), do_expect2(Check, any, Err, any, any, To); %% exp_varbinds() -> [exp_varbind()] @@ -943,25 +952,23 @@ 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]), + io_format_expect("'get-response'" + "~n with" + "~n Varbinds: ~p", [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]), + io_format_expect("'snmpv2-trap' with" + "~n Varbinds: ~p", [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]), + io_format_expect("'report' with" + "~n Varbinds: ~p", [ExpVBs]), do_expect2(Check, 'report', noError, 0, ExpVBs, get_timeout()); @@ -970,9 +977,8 @@ do_expect(inform, ExpVBs) -> do_expect({inform, false}, ExpVBs) -> Check = fun(_, R) -> R end, - io:format("EXPECT 'inform-request' (false)" - "~n with" - "~n Varbinds: ~p~n", [ExpVBs]), + io_format_expect("'inform-request' (false) with" + "~n Varbinds: ~p", [ExpVBs]), do_expect2(Check, 'inform-request', noError, 0, ExpVBs, get_timeout()); do_expect({inform, true}, ExpVBs) -> @@ -986,9 +992,8 @@ do_expect({inform, true}, ExpVBs) -> (_, Err) -> Err end, - io:format("EXPECT 'inform-request' (true)" - "~n with" - "~n Varbinds: ~p~n", [ExpVBs]), + io_format_expect("'inform-request' (true) with" + "~n Varbinds: ~p", [ExpVBs]), do_expect2(Check, 'inform-request', noError, 0, ExpVBs, get_timeout()); do_expect({inform, {error, EStat, EIdx}}, ExpVBs) @@ -1003,11 +1008,10 @@ 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]), + io_format_expect("'inform-request' (error) with" + "~n Error Status: ~p" + "~n Error Index: ~p" + "~n Varbinds: ~p", [EStat, EIdx, ExpVBs]), do_expect2(Check, 'inform-request', noError, 0, ExpVBs, get_timeout()). @@ -1018,26 +1022,23 @@ 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]), + io_format_expect("'get-response' withing ~w ms with" + "~n Error: ~p" + "~n Index: ~p" + "~n Varbinds: ~p", [To, Err, Idx, ExpVBs]), do_expect2(Check, 'get-response', Err, Idx, ExpVBs, To). do_expect(Type, Enterp, Generic, Specific, ExpVBs) -> - do_expect(Type, Enterp, Generic, Specific, ExpVBs, 3500). + do_expect(Type, Enterp, Generic, Specific, ExpVBs, get_timeout()). do_expect(trap, Enterp, Generic, Specific, ExpVBs, To) -> - 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]), + io_format_expect("trap within ~w ms with" + "~n Enterp: ~w" + "~n Generic: ~w" + "~n Specific: ~w" + "~n Varbinds: ~w", + [To, Enterp, Generic, Specific, ExpVBs]), PureE = purify_oid(Enterp), case receive_trap(To) of #trappdu{enterprise = PureE, @@ -1072,46 +1073,46 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To) #pdu{type = Type, error_status = Err, error_index = Idx} when ExpVBs =:= any -> - io:format("EXPECT received expected pdu (1)~n", []), + io_format_expect("received expected pdu (1)"), 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]), + io_format_expect("received expected pdu with " + "unexpected error status (2): " + "~n Error Status: ~p", [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", []), + io_format_expect("received expected pdu (3)"), 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]), + io_format_expect("received expected pdu with " + "unexpected error status (4): " + "~n Error Status: ~p", [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", []), + io_format_expect("received expected pdu (5)", []), 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]), + io_format_expect("received expected pdu with " + "unexpected error status (6): " + "~n Error Status: ~p", [Err2]), {error, {unexpected_error_status, Err, Err2, ReqId}}; #pdu{type = Type, @@ -1120,13 +1121,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", []), + io_format_expect("received expected pdu with " + "expected error index (7)"), ok; false -> - io:format("EXPECT received expected pdu with " - "unexpected error index (8): " - "~n Error Index: ~p~n", [EI]), + io_format_expect("received expected pdu with " + "unexpected error index (8): " + "~n Error Index: ~p", [EI]), {error, {unexpected_error_index, EI, Idx, ReqId}} end; @@ -1136,15 +1137,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]), + io_format_expect("received expected pdu with " + "unexpected error status (9): " + "~n Error Status: ~p", [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]), + io_format_expect("received expected pdu with " + "unexpected error (10): " + "~n Error Status: ~p" + "~n Error index: ~p", [Err2, EI]), {error, {unexpected_error, {Err, Idx}, {Err2, EI}, ReqId}} end; @@ -1152,12 +1153,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]), + io_format_expect("received unexpected pdu with (11) " + "~n Type: ~p" + "~n ReqId: ~p" + "~n Errot status: ~p" + "~n Error index: ~p", + [Type2, ReqId, Err2, Idx2]), {error, {unexpected_pdu, {Type, Err, Idx}, {Type2, Err2, Idx2}, ReqId}}; @@ -1166,26 +1167,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]), + 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", + [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]), + io_format_expect("received pdu (13): " + "~n [exp] Type: ~p" + "~n [exp] Error Status: ~p" + "~n VBs: ~p" + "~nwhen" + "~n ExpVBs: ~p", + [Type, Err, VBs, ExpVBs]), Check(PDU, check_vbs(purify_oids(ExpVBs), VBs)); #pdu{type = Type, @@ -1193,15 +1194,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]), + 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", + [Type, ReqId, Err, EI, VBs, ExpVBs]), PureVBs = purify_oids(ExpVBs), case lists:member(EI, Idx) of true -> @@ -1215,13 +1216,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]), + 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", + [Type2, ReqId, Err2, Idx2, VBs2]), {error, {unexpected_pdu, {Type, Err, Idx, purify_oids(ExpVBs)}, @@ -1229,9 +1230,8 @@ do_expect2(Check, Type, Err, Idx, ExpVBs, To) ReqId}}; Error -> - io:format("EXPECT received error (16): " - "~n Error: ~p" - "~n", [Error]), + io_format_expect("received error (16): " + "~n Error: ~p", [Error]), Error end. -- cgit v1.2.3 From 8bd83e6a805ee15c52e239e8d404e1d3e1021048 Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Wed, 3 Apr 2019 17:53:30 +0200 Subject: [snmp|agent|test] Agent test manager start fix The agent test manager had a bug during start that could potentially cause deadlock, but atleast could cause test cases to fail because of timeouts. The test manager (actually the "packet server") used proc_lib to start the process but it called the init_ack function before the init was actually complete. This was only a problem for v3 cases (where it did a bunch of further inits, including starting the local-db process). Also did debug/verbosity tweaking. Added a bunch of debug (verbosity) printouts for the agent test manager "packet server" during v3 init. Also made sure we could distinguish the "normal" local-db from the one used by the test manager (this is done by using a new short-name). --- lib/snmp/src/agent/snmpa_local_db.erl | 4 ++-- lib/snmp/src/misc/snmp_verbosity.erl | 3 ++- lib/snmp/test/snmp_test_mgr_misc.erl | 23 +++++++++++++++++------ 3 files changed, 21 insertions(+), 9 deletions(-) (limited to 'lib') diff --git a/lib/snmp/src/agent/snmpa_local_db.erl b/lib/snmp/src/agent/snmpa_local_db.erl index eb67b9cd6f..f481fe9970 100644 --- a/lib/snmp/src/agent/snmpa_local_db.erl +++ b/lib/snmp/src/agent/snmpa_local_db.erl @@ -147,8 +147,8 @@ init([Prio, DbDir, DbInitError, Opts]) -> do_init(Prio, DbDir, DbInitError, Opts) -> process_flag(priority, Prio), process_flag(trap_exit, true), - put(sname,ldb), - put(verbosity,get_opt(verbosity, Opts, ?default_verbosity)), + put(sname, get_opt(sname, Opts, ldb)), + put(verbosity, get_opt(verbosity, Opts, ?default_verbosity)), ?vlog("starting",[]), Dets = dets_open(DbDir, DbInitError, Opts), Ets = ets:new(?ETS_TAB, [set, protected]), diff --git a/lib/snmp/src/misc/snmp_verbosity.erl b/lib/snmp/src/misc/snmp_verbosity.erl index edfb52a474..bca4bad283 100644 --- a/lib/snmp/src/misc/snmp_verbosity.erl +++ b/lib/snmp/src/misc/snmp_verbosity.erl @@ -155,7 +155,8 @@ image_of_sname(mgr) -> "MGR"; image_of_sname(mgr_misc) -> "MGR_MISC"; image_of_sname(undefined) -> ""; -image_of_sname(V) -> lists:flatten(io_lib:format("~p",[V])). +image_of_sname(N) when is_list(N) -> N; % Used in testing +image_of_sname(N) -> lists:flatten(io_lib:format("~p", [N])). validate(info) -> info; diff --git a/lib/snmp/test/snmp_test_mgr_misc.erl b/lib/snmp/test/snmp_test_mgr_misc.erl index 9e76452345..89d6f93a88 100644 --- a/lib/snmp/test/snmp_test_mgr_misc.erl +++ b/lib/snmp/test/snmp_test_mgr_misc.erl @@ -38,6 +38,7 @@ -define(SNMP_USE_V3, true). -include_lib("snmp/include/snmp_types.hrl"). +-include_lib("snmp/src/misc/snmp_verbosity.hrl"). %%---------------------------------------------------------------------- @@ -101,11 +102,11 @@ init_packet( DbgOptions, IpFamily) -> put(sname, mgr_misc), init_debug(DbgOptions), - {ok, UdpId} = - gen_udp:open(TrapUdp, [{recbuf,BufSz}, {reuseaddr, true}, IpFamily]), + UdpOpts = [{recbuf,BufSz}, {reuseaddr, true}, IpFamily], + {ok, UdpId} = gen_udp:open(TrapUdp, UdpOpts), put(msg_id, 1), - proc_lib:init_ack(Parent, self()), init_usm(Version, Dir), + proc_lib:init_ack(Parent, self()), packet_loop(SnmpMgr, UdpId, AgentIp, UdpPort, VsnHdr, Version, []). init_debug(Dbg) when is_atom(Dbg) -> @@ -598,15 +599,25 @@ set_pdu(Msg, RePdu) -> 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}), - snmpa_local_db:start_link(normal, Dir, [{verbosity,trace}]), + ?vlog("init_usm -> try start fake local-db", []), + {ok, _} = snmpa_local_db:start_link(normal, Dir, + [{sname, "MGR-LOCAL-DB"}, + {verbosity, trace}]), NameDb = snmpa_agent:db(snmpEngineID), + ?vlog("init_usm -> try set manager engine-id", []), R = snmp_generic:variable_set(NameDb, "mgrEngine"), - io:format("~w:init_usm -> engine-id set result: ~p~n", [?MODULE,R]), + snmp_verbosity:print(info, info, "init_usm -> engine-id set result: ~p", [R]), + ?vlog("init_usm -> try set engine boots (framework-mib)", []), snmp_framework_mib:set_engine_boots(1), + ?vlog("init_usm -> try set engine time (framework-mib)", []), snmp_framework_mib:set_engine_time(1), - snmp_user_based_sm_mib:reconfigure(Dir); + ?vlog("init_usm -> try usm (mib) reconfigure", []), + snmp_user_based_sm_mib:reconfigure(Dir), + ?vlog("init_usm -> done", []), + ok; init_usm(_Vsn, _Dir) -> ok. -- cgit v1.2.3 From dcd4ba6359ede0f51a2aec9c8ba536e319c36dfa Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Thu, 4 Apr 2019 10:53:04 +0200 Subject: [snmp|agent|test] The agent test local-db may already be started Handle when the agent test manager starts the fake local-db and that process is already running (for some reason). --- lib/snmp/test/snmp_test_mgr_misc.erl | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) (limited to 'lib') diff --git a/lib/snmp/test/snmp_test_mgr_misc.erl b/lib/snmp/test/snmp_test_mgr_misc.erl index 89d6f93a88..b52cd06bd5 100644 --- a/lib/snmp/test/snmp_test_mgr_misc.erl +++ b/lib/snmp/test/snmp_test_mgr_misc.erl @@ -603,9 +603,15 @@ init_usm('version-3', Dir) -> ets:new(snmp_agent_table, [set, public, named_table]), ets:insert(snmp_agent_table, {agent_mib_storage, persistent}), ?vlog("init_usm -> try start fake local-db", []), - {ok, _} = snmpa_local_db:start_link(normal, Dir, - [{sname, "MGR-LOCAL-DB"}, - {verbosity, trace}]), + case snmpa_local_db:start_link(normal, Dir, + [{sname, "MGR-LOCAL-DB"}, + {verbosity, trace}]) of + {ok, _} -> + ok; + {error, {already_started, Pid}} -> + ?vlog("already started: ~p" + "~n ~p", [process_info(Pid)]) + end, NameDb = snmpa_agent:db(snmpEngineID), ?vlog("init_usm -> try set manager engine-id", []), R = snmp_generic:variable_set(NameDb, "mgrEngine"), -- cgit v1.2.3 From 5ac8a73af358e47666e4a3bb6bbe3edbfe98bf36 Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Fri, 5 Apr 2019 12:37:19 +0200 Subject: [snmp|agent|test] More test tweaking Improved test printouts (more with timestamps), also fixed the printouts of the (fake) local-db start result printout. Also updated the copyright end-dates. --- lib/snmp/src/agent/snmpa_agent.erl | 2 +- lib/snmp/src/agent/snmpa_local_db.erl | 4 +- lib/snmp/test/snmp_agent_test.erl | 2 +- lib/snmp/test/snmp_agent_test_lib.erl | 46 +++++++++++++--------- lib/snmp/test/snmp_test_lib.erl | 26 ++++++++++-- lib/snmp/test/snmp_test_lib.hrl | 25 +++++++----- lib/snmp/test/snmp_test_mgr.erl | 74 +++++++++++++++++++---------------- lib/snmp/test/snmp_test_mgr_misc.erl | 21 ++++++---- 8 files changed, 122 insertions(+), 78 deletions(-) (limited to 'lib') diff --git a/lib/snmp/src/agent/snmpa_agent.erl b/lib/snmp/src/agent/snmpa_agent.erl index 2225a40996..1dd989e113 100644 --- a/lib/snmp/src/agent/snmpa_agent.erl +++ b/lib/snmp/src/agent/snmpa_agent.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 1996-2016. All Rights Reserved. +%% Copyright Ericsson AB 1996-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. diff --git a/lib/snmp/src/agent/snmpa_local_db.erl b/lib/snmp/src/agent/snmpa_local_db.erl index f481fe9970..0231977c46 100644 --- a/lib/snmp/src/agent/snmpa_local_db.erl +++ b/lib/snmp/src/agent/snmpa_local_db.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 1996-2016. All Rights Reserved. +%% Copyright Ericsson AB 1996-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. @@ -625,7 +625,7 @@ handle_info(Info, State) -> terminate(Reason, State) -> - ?vlog("terminate: ~p",[Reason]), + ?vlog("terminate: ~p", [Reason]), close(State). diff --git a/lib/snmp/test/snmp_agent_test.erl b/lib/snmp/test/snmp_agent_test.erl index b71614ed51..c4365e6a96 100644 --- a/lib/snmp/test/snmp_agent_test.erl +++ b/lib/snmp/test/snmp_agent_test.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 2003-2018. All Rights Reserved. +%% Copyright Ericsson AB 2003-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. diff --git a/lib/snmp/test/snmp_agent_test_lib.erl b/lib/snmp/test/snmp_agent_test_lib.erl index 8749df0c3f..70e2e5f235 100644 --- a/lib/snmp/test/snmp_agent_test_lib.erl +++ b/lib/snmp/test/snmp_agent_test_lib.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 2005-2016. All Rights Reserved. +%% Copyright Ericsson AB 2005-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. @@ -358,22 +358,22 @@ run(Mod, Func, Args, Opts) -> "~n StdM: ~p", [M,Vsn,Dir,User,SecLevel,EngineID,CtxEngineID,Community,StdM]), case snmp_test_mgr:start([%% {agent, snmp_test_lib:hostname()}, - {packet_server_debug,true}, - {debug,true}, - {agent, get(master_host)}, - {ipfamily, get(ipfamily)}, - {agent_udp, 4000}, - {trap_udp, 5000}, - {recbuf,65535}, + {packet_server_debug, true}, + {debug, true}, + {agent, get(master_host)}, + {ipfamily, get(ipfamily)}, + {agent_udp, 4000}, + {trap_udp, 5000}, + {recbuf, 65535}, quiet, Vsn, - {community, Community}, - {user, User}, - {sec_level, SecLevel}, - {engine_id, EngineID}, - {context_engine_id, CtxEngineID}, - {dir, Dir}, - {mibs, mibs(StdM, M)}]) of + {community, Community}, + {user, User}, + {sec_level, SecLevel}, + {engine_id, EngineID}, + {context_engine_id, CtxEngineID}, + {dir, Dir}, + {mibs, mibs(StdM, M)}]) of {ok, _Pid} -> case (catch apply(Mod, Func, Args)) of {'EXIT', Reason} -> @@ -383,10 +383,18 @@ run(Mod, Func, Args, Opts) -> catch snmp_test_mgr:stop(), Res end; + + {error, Reason} -> + ?EPRINT2("Failed starting (test) manager: " + "~n ~p", [Reason]), + catch snmp_test_mgr:stop(), + ?line ?FAIL({mgr_start_error, Reason}); + Err -> - io:format("Error starting manager: ~p\n", [Err]), + ?EPRINT2("Failed starting (test) manager: " + "~n ~p", [Err]), catch snmp_test_mgr:stop(), - ?line ?FAIL({mgr_start, Err}) + ?line ?FAIL({mgr_start_failure, Err}) end. @@ -905,8 +913,8 @@ io_format_expect(F) -> io_format_expect(F, []). io_format_expect(F, A) -> - FTS = snmp_test_lib:formated_timestamp(), - io:format("[~s] EXPECT " ++ F ++ "~n", [FTS | A]). + ?PRINT2("EXPECT " ++ F, A). + do_expect(Expect) when is_atom(Expect) -> do_expect({Expect, get_timeout()}); diff --git a/lib/snmp/test/snmp_test_lib.erl b/lib/snmp/test/snmp_test_lib.erl index 290f1bc31a..4973630ea2 100644 --- a/lib/snmp/test/snmp_test_lib.erl +++ b/lib/snmp/test/snmp_test_lib.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 2002-2015. All Rights Reserved. +%% Copyright Ericsson AB 2002-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. @@ -41,7 +41,7 @@ -export([watchdog/3, watchdog_start/1, watchdog_start/2, watchdog_stop/1]). -export([del_dir/1]). -export([cover/1]). --export([p/2, print/5, formated_timestamp/0]). +-export([p/2, print1/2, print2/2, print/5, formated_timestamp/0]). %% ---------------------------------------------------------------------- @@ -605,6 +605,24 @@ p(Mod, Case) when is_atom(Mod) andalso is_atom(Case) -> p(F, A) when is_list(F) andalso is_list(A) -> io:format(user, F ++ "~n", A). +%% This is just a bog standard printout, with a (formatted) timestamp +%% prefix and a newline after. +%% print1 prints to both standard_ío and to user. print2 just to standard_ío. + +print_format(F, A) -> + FTS = snmp_test_lib:formated_timestamp(), + io_lib:format("[~s] " ++ F ++ "~n", [FTS | A]). + +print1(F, A) -> + S = print_format(F, A), + io:format("~s", [S]), + io:format(user, "~s", [S]). + +print2(F, A) -> + S = print_format(F, A), + io:format("~s", [S]). + + print(Prefix, Module, Line, Format, Args) -> io:format("*** [~s] ~s ~p ~p ~p:~p *** " ++ Format ++ "~n", [formated_timestamp(), @@ -618,6 +636,6 @@ format_timestamp({_N1, _N2, N3} = Now) -> {YYYY,MM,DD} = Date, {Hour,Min,Sec} = Time, FormatDate = - io_lib:format("~.4w:~.2.0w:~.2.0w ~.2.0w:~.2.0w:~.2.0w ~w", - [YYYY,MM,DD,Hour,Min,Sec,round(N3/1000)]), + io_lib:format("~.4w:~.2.0w:~.2.0w-~.2.0w:~.2.0w:~.2.0w.~w", + [YYYY, MM, DD, Hour, Min, Sec, round(N3/1000)]), lists:flatten(FormatDate). diff --git a/lib/snmp/test/snmp_test_lib.hrl b/lib/snmp/test/snmp_test_lib.hrl index 7acebee1f1..335f3fff3c 100644 --- a/lib/snmp/test/snmp_test_lib.hrl +++ b/lib/snmp/test/snmp_test_lib.hrl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 2002-2015. All Rights Reserved. +%% Copyright Ericsson AB 2002-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. @@ -127,24 +127,31 @@ -endif. -ifdef(snmp_debug). --define(DBG(F,A),?PRINT("DBG",F,A)). +-define(DBG(F,A), ?PRINT("DBG", F, A)). -else. --define(DBG(F,A),ok). +-define(DBG(F,A), ok). -endif. -ifdef(snmp_log). --define(LOG(F,A),?PRINT("LOG",F,A)). +-define(LOG(F,A), ?PRINT("LOG", F, A)). -else. --define(LOG(F,A),ok). +-define(LOG(F,A), ok). -endif. -ifdef(snmp_error). --define(ERR(F,A),?PRINT("ERR",F,A)). +-define(ERR(F,A), ?PRINT("ERR", F, A)). -else. --define(ERR(F,A),ok). +-define(ERR(F,A), ok). -endif. --define(INF(F,A),?PRINT("INF",F,A)). +-define(INF(F,A), ?PRINT("INF", F, A)). -define(PRINT(P,F,A), - snmp_test_lib:print(P,?MODULE,?LINE,F,A)). + snmp_test_lib:print(P, ?MODULE, ?LINE, F, A)). + +-define(PRINT1(F, A), snmp_test_lib:print1(F, A)). +-define(EPRINT1(F, A), ?PRINT1(" " ++ F, A)). + +-define(PRINT2(F, A), snmp_test_lib:print2(F, A)). +-define(EPRINT2(F, A), ?PRINT2(" " ++ F, A)). + diff --git a/lib/snmp/test/snmp_test_mgr.erl b/lib/snmp/test/snmp_test_mgr.erl index 36637d5cf4..73a4d56084 100644 --- a/lib/snmp/test/snmp_test_mgr.erl +++ b/lib/snmp/test/snmp_test_mgr.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 1996-2015. All Rights Reserved. +%% Copyright Ericsson AB 1996-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. @@ -20,8 +20,10 @@ -module(snmp_test_mgr). + %%---------------------------------------------------------------------- -%% This module implements a simple SNMP manager for Erlang. +%% This module implements a simple SNMP manager for Erlang. Its used +%% during by the agent test suite. %%---------------------------------------------------------------------- %% c(snmp_test_mgr). @@ -49,16 +51,17 @@ -include_lib("snmp/include/snmp_types.hrl"). -include_lib("snmp/include/STANDARD-MIB.hrl"). - --record(state,{dbg = true, - quiet, - parent, - timeout = 3500, - print_traps = true, - mini_mib, - packet_server, - last_sent_pdu, - last_received_pdu}). +-include("snmp_test_lib.hrl"). + +-record(state, {dbg = true, + quiet, + parent, + timeout = 3500, + print_traps = true, + mini_mib, + packet_server, + last_sent_pdu, + last_received_pdu}). -define(SERVER, ?MODULE). -define(PACK_SERV, snmp_test_mgr_misc). @@ -197,27 +200,28 @@ init({Options, CallerPid}) -> put(debug, get_value(debug, Options, false)), d("init -> (~p) extract options",[self()]), PacksDbg = get_value(packet_server_debug, Options, false), - io:format("[~w] ~p -> PacksDbg: ~p~n", [?MODULE, self(), PacksDbg]), + print("[~w] ~p -> PacksDbg: ~p~n", [?MODULE, self(), PacksDbg]), RecBufSz = get_value(recbuf, Options, 1024), - io:format("[~w] ~p -> RecBufSz: ~p~n", [?MODULE, self(), RecBufSz]), + print("[~w] ~p -> RecBufSz: ~p~n", [?MODULE, self(), RecBufSz]), Mibs = get_value(mibs, Options, []), - io:format("[~w] ~p -> Mibs: ~p~n", [?MODULE, self(), Mibs]), + print("[~w] ~p -> Mibs: ~p~n", [?MODULE, self(), Mibs]), Udp = get_value(agent_udp, Options, 4000), - io:format("[~w] ~p -> Udp: ~p~n", [?MODULE, self(), Udp]), + print("[~w] ~p -> Udp: ~p~n", [?MODULE, self(), Udp]), User = get_value(user, Options, "initial"), - io:format("[~w] ~p -> User: ~p~n", [?MODULE, self(), User]), + print("[~w] ~p -> User: ~p~n", [?MODULE, self(), User]), EngineId = get_value(engine_id, Options, "agentEngine"), - io:format("[~w] ~p -> EngineId: ~p~n", [?MODULE, self(), EngineId]), + print("[~w] ~p -> EngineId: ~p~n", [?MODULE, self(), EngineId]), CtxEngineId = get_value(context_engine_id, Options, EngineId), - io:format("[~w] ~p -> CtxEngineId: ~p~n", [?MODULE, self(), CtxEngineId]), + print("[~w] ~p -> CtxEngineId: ~p~n", [?MODULE, self(), CtxEngineId]), TrapUdp = get_value(trap_udp, Options, 5000), - io:format("[~w] ~p -> TrapUdp: ~p~n", [?MODULE, self(), TrapUdp]), + print("[~w] ~p -> TrapUdp: ~p~n", [?MODULE, self(), TrapUdp]), Dir = get_value(dir, Options, "."), - io:format("[~w] ~p -> Dir: ~p~n", [?MODULE, self(), Dir]), + print("[~w] ~p -> Dir: ~p~n", [?MODULE, self(), Dir]), SecLevel = get_value(sec_level, Options, noAuthNoPriv), - io:format("[~w] ~p -> SecLevel: ~p~n", [?MODULE, self(), SecLevel]), + print("[~w] ~p -> SecLevel: ~p~n", [?MODULE, self(), SecLevel]), MiniMIB = snmp_mini_mib:create(Mibs), - io:format("[~w] ~p -> MiniMIB: ~p~n", [?MODULE, self(), MiniMIB]), + d("[~w] ~p -> MiniMIB: " + "~n ~p", [?MODULE, self(), MiniMIB]), Version = case lists:member(v2, Options) of true -> 'version-2'; false -> @@ -226,19 +230,19 @@ init({Options, CallerPid}) -> false -> 'version-1' end end, - io:format("[~w] ~p -> Version: ~p~n", [?MODULE, self(), Version]), + print("[~w] ~p -> Version: ~p~n", [?MODULE, self(), Version]), Com = case Version of 'version-3' -> get_value(context, Options, ""); _ -> get_value(community, Options, "public") end, - io:format("[~w] ~p -> Com: ~p~n", [?MODULE, self(), Com]), + print("[~w] ~p -> Com: ~p~n", [?MODULE, self(), Com]), VsnHdrD = {Com, User, EngineId, CtxEngineId, mk_seclevel(SecLevel)}, - io:format("[~w] ~p -> VsnHdrD: ~p~n", [?MODULE, self(), VsnHdrD]), + print("[~w] ~p -> VsnHdrD: ~p~n", [?MODULE, self(), VsnHdrD]), IpFamily = get_value(ipfamily, Options, inet), - io:format("[~w] ~p -> IpFamily: ~p~n", [?MODULE, self(), IpFamily]), + print("[~w] ~p -> IpFamily: ~p~n", [?MODULE, self(), IpFamily]), AgIp = case snmp_misc:assq(agent, Options) of {value, Tuple4} when is_tuple(Tuple4) andalso (size(Tuple4) =:= 4) -> @@ -247,9 +251,9 @@ init({Options, CallerPid}) -> {ok, Ip} = snmp_misc:ip(Host, IpFamily), Ip end, - io:format("[~w] ~p -> AgIp: ~p~n", [?MODULE, self(), AgIp]), + print("[~w] ~p -> AgIp: ~p~n", [?MODULE, self(), AgIp]), Quiet = lists:member(quiet, Options), - io:format("[~w] ~p -> Quiet: ~p~n", [?MODULE, self(), Quiet]), + print("[~w] ~p -> Quiet: ~p~n", [?MODULE, self(), Quiet]), PackServ = start_packet_server( Quiet, Options, CallerPid, AgIp, Udp, TrapUdp, @@ -443,7 +447,8 @@ handle_cast({bulk, Args}, State) -> {noreply, execute_request(bulk, Args, State)}; handle_cast({response, RespPdu}, State) -> - d("handle_cast -> response request with ~p", [RespPdu]), + d("handle_cast -> response request with " + "~n ~p", [RespPdu]), ?PACK_SERV:send_pdu(RespPdu, State#state.packet_server), {noreply, State}; @@ -1126,14 +1131,15 @@ sizeOf(L) when is_list(L) -> sizeOf(B) when is_binary(B) -> size(B). -d(F,A) -> d(get(debug),F,A). +d(F, A) -> d(get(debug), F, A). -d(true,F,A) -> - io:format("*** [~s] MGR_DBG *** " ++ F ++ "~n", - [formated_timestamp()|A]); +d(true, F, A) -> + print(F, A); d(_,_F,_A) -> ok. +print(F, A) -> + ?PRINT2("MGR " ++ F, A). formated_timestamp() -> snmp_test_lib:formated_timestamp(). diff --git a/lib/snmp/test/snmp_test_mgr_misc.erl b/lib/snmp/test/snmp_test_mgr_misc.erl index b52cd06bd5..badbbad894 100644 --- a/lib/snmp/test/snmp_test_mgr_misc.erl +++ b/lib/snmp/test/snmp_test_mgr_misc.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 1996-2016. All Rights Reserved. +%% Copyright Ericsson AB 1996-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. @@ -39,11 +39,13 @@ -define(SNMP_USE_V3, true). -include_lib("snmp/include/snmp_types.hrl"). -include_lib("snmp/src/misc/snmp_verbosity.hrl"). +-include("snmp_test_lib.hrl"). %%---------------------------------------------------------------------- %% The InHandler process will receive messages on the form {snmp_pdu, Pdu}. %%---------------------------------------------------------------------- + start_link_packet( InHandler, AgentIp, UdpPort, TrapUdp, VsnHdr, Version, Dir, BufSz) -> start_link_packet( @@ -606,11 +608,12 @@ init_usm('version-3', Dir) -> case snmpa_local_db:start_link(normal, Dir, [{sname, "MGR-LOCAL-DB"}, {verbosity, trace}]) of - {ok, _} -> - ok; + {ok, Pid} -> + ?vlog("started: ~p" + "~n ~p", [Pid, process_info(Pid)]); {error, {already_started, Pid}} -> ?vlog("already started: ~p" - "~n ~p", [process_info(Pid)]) + "~n ~p", [Pid, process_info(Pid)]) end, NameDb = snmpa_agent:db(snmpEngineID), ?vlog("init_usm -> try set manager engine-id", []), @@ -819,13 +822,15 @@ sz(O) -> {unknown_size, O}. d(F) -> d(F, []). -d(F,A) -> d(get(debug),F,A). +d(F,A) -> d(get(debug), F, A). -d(true,F,A) -> - io:format("*** [~s] MGR_PS_DBG *** " ++ F ++ "~n", - [formated_timestamp()|A]); +d(true, F, A) -> + print(F, A); d(_,_F,_A) -> ok. +print(F, A) -> + ?PRINT2("MGR_PS " ++ F, A). + formated_timestamp() -> snmp_test_lib:formated_timestamp(). -- cgit v1.2.3 From 0d125432b4a33c0f4ef1e179e60a8e842125227c Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Fri, 5 Apr 2019 18:12:15 +0200 Subject: [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. --- lib/snmp/src/agent/snmpa_local_db.erl | 1 + lib/snmp/src/misc/snmp_misc.erl | 118 +++++++++++++++++++++++++++++++++- lib/snmp/src/misc/snmp_verbosity.erl | 13 +--- lib/snmp/test/snmp_test_lib.erl | 15 ++--- lib/snmp/test/snmp_test_mgr_misc.erl | 71 ++++++++++++++++++-- 5 files changed, 189 insertions(+), 29 deletions(-) (limited to 'lib') diff --git a/lib/snmp/src/agent/snmpa_local_db.erl b/lib/snmp/src/agent/snmpa_local_db.erl index 0231977c46..f481641242 100644 --- a/lib/snmp/src/agent/snmpa_local_db.erl +++ b/lib/snmp/src/agent/snmpa_local_db.erl @@ -153,6 +153,7 @@ do_init(Prio, DbDir, DbInitError, Opts) -> Dets = dets_open(DbDir, DbInitError, Opts), Ets = ets:new(?ETS_TAB, [set, protected]), ?vdebug("started",[]), + put(started, snmp_misc:formated_timestamp()), {ok, #state{dets = Dets, ets = Ets}}. dets_open(DbDir, DbInitError, Opts) -> diff --git a/lib/snmp/src/misc/snmp_misc.erl b/lib/snmp/src/misc/snmp_misc.erl index 1f847b7a29..0cc04d4056 100644 --- a/lib/snmp/src/misc/snmp_misc.erl +++ b/lib/snmp/src/misc/snmp_misc.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 1996-2015. All Rights Reserved. +%% Copyright Ericsson AB 1996-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. @@ -64,8 +64,18 @@ strip_extension_from_filename/2, str_xor/2, time/3, - - verify_behaviour/2 + + verify_behaviour/2, + + %% These are used both for debugging (verbosity printouts) + %% and other such "utility" operations. + format_timestamp/1, format_timestamp/2, + format_short_timestamp/1, format_short_timestamp/2, + format_long_timestamp/1, format_long_timestamp/2, + formated_timestamp/0, + formated_short_timestamp/0, + formated_long_timestamp/0 + ]). @@ -112,6 +122,108 @@ now(sec) -> erlang:monotonic_time(seconds). + +%% --------------------------------------------------------------------------- +%% # formated_timstamp/0, formated_timstamp/1 +%% # format_short_timstamp/0, format_short_timstamp/1 +%% # format_long_timstamp/0, format_long_timstamp/1 +%% +%% Create a formatted timestamp. Short means that it will not include +%% the date in the formatted timestamp. Also it will only include millis. +%% --------------------------------------------------------------------------- + +formated_timestamp() -> + formated_long_timestamp(). + +formated_short_timestamp() -> + format_short_timestamp(os:timestamp()). + +formated_long_timestamp() -> + format_long_timestamp(os:timestamp()). + + +%% --------------------------------------------------------------------------- +%% # format_timstamp/1, format_timstamp/2 +%% # format_short_timstamp/1, format_short_timstamp/2 +%% # format_long_timstamp/1, format_long_timstamp/2 +%% +%% Formats the provided timestamp. Short means that it will not include +%% the date in the formatted timestamp. +%% --------------------------------------------------------------------------- + +-spec format_timestamp(Now :: os:timestamp()) -> + string(). + +format_timestamp(Now) -> + format_long_timestamp(Now). + +-spec format_short_timestamp(Now :: os:timestamp()) -> + string(). + +format_short_timestamp(Now) -> + N2T = fun(N) -> calendar:now_to_local_time(N) end, + format_timestamp(short, Now, N2T). + +-spec format_long_timestamp(Now :: os:timestamp()) -> + string(). + +format_long_timestamp(Now) -> + N2T = fun(N) -> calendar:now_to_local_time(N) end, + format_timestamp(long, Now, N2T). + +-spec format_timestamp(Now :: os:timestamp(), + N2T :: function()) -> + string(). + +format_timestamp(Now, N2T) when is_tuple(Now) andalso is_function(N2T) -> + format_long_timestamp(Now, N2T). + +-spec format_short_timestamp(Now :: os:timestamp(), + N2T :: function()) -> + string(). + +format_short_timestamp(Now, N2T) when is_tuple(Now) andalso is_function(N2T) -> + format_timestamp(short, Now, N2T). + +-spec format_long_timestamp(Now :: os:timestamp(), + N2T :: function()) -> + string(). + +format_long_timestamp(Now, N2T) when is_tuple(Now) andalso is_function(N2T) -> + format_timestamp(long, Now, N2T). + +format_timestamp(Format, {_N1, _N2, N3} = Now, N2T) -> + {Date, Time} = N2T(Now), + do_format_timestamp(Format, Date, Time, N3). + %% case Format of + %% short -> + %% do_format_short_timestamp(Time, N3); + %% long -> + %% do_format_long_timestamp(Date, Time, N3) + %% end. + +do_format_timestamp(short, Date, Time, N3) -> + do_format_short_timestamp(Time, N3); +do_format_timestamp(long, Date, Time, N3) -> + do_format_long_timestamp(Date, Time, N3). + +do_format_long_timestamp(Date, Time, N3) -> + {YYYY,MM,DD} = Date, + {Hour,Min,Sec} = Time, + FormatDate = + io_lib:format("~.4w-~.2.0w-~.2.0w ~.2.0w:~.2.0w:~.2.0w.~.3.0w", + [YYYY, MM, DD, Hour, Min, Sec, N3 div 1000]), + lists:flatten(FormatDate). + +do_format_short_timestamp(Time, N3) -> + {Hour,Min,Sec} = Time, + FormatDate = + io_lib:format("~.2.0w:~.2.0w:~.2.0w.~.3.0w", + [Hour, Min, Sec, N3 div 1000]), + lists:flatten(FormatDate). + + + is_crypto_supported(Alg) -> %% The 'try catch' handles the case when 'crypto' is %% not present in the system (or not started). diff --git a/lib/snmp/src/misc/snmp_verbosity.erl b/lib/snmp/src/misc/snmp_verbosity.erl index bca4bad283..9b2676d048 100644 --- a/lib/snmp/src/misc/snmp_verbosity.erl +++ b/lib/snmp/src/misc/snmp_verbosity.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 2000-2015. All Rights Reserved. +%% Copyright Ericsson AB 2000-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. @@ -70,16 +70,7 @@ print2(_Verbosity,Format,Arguments) -> timestamp() -> - format_timestamp(os:timestamp()). - -format_timestamp({_N1, _N2, N3} = Now) -> - {Date, Time} = calendar:now_to_datetime(Now), - {YYYY,MM,DD} = Date, - {Hour,Min,Sec} = Time, - FormatDate = - io_lib:format("~.4w:~.2.0w:~.2.0w ~.2.0w:~.2.0w:~.2.0w ~w", - [YYYY,MM,DD,Hour,Min,Sec,round(N3/1000)]), - lists:flatten(FormatDate). + snmp_misc:formated_timestamp(). process_args([], Acc) -> lists:reverse(Acc); diff --git a/lib/snmp/test/snmp_test_lib.erl b/lib/snmp/test/snmp_test_lib.erl index 4973630ea2..33f7b89974 100644 --- a/lib/snmp/test/snmp_test_lib.erl +++ b/lib/snmp/test/snmp_test_lib.erl @@ -607,7 +607,8 @@ p(F, A) when is_list(F) andalso is_list(A) -> %% This is just a bog standard printout, with a (formatted) timestamp %% prefix and a newline after. -%% print1 prints to both standard_ío and to user. print2 just to standard_ío. +%% print1 - prints to both standard_io and user. +%% print2 - prints to just standard_io. print_format(F, A) -> FTS = snmp_test_lib:formated_timestamp(), @@ -629,13 +630,5 @@ print(Prefix, Module, Line, Format, Args) -> Prefix, node(), self(), Module, Line|Args]). formated_timestamp() -> - format_timestamp(os:timestamp()). - -format_timestamp({_N1, _N2, N3} = Now) -> - {Date, Time} = calendar:now_to_datetime(Now), - {YYYY,MM,DD} = Date, - {Hour,Min,Sec} = Time, - FormatDate = - io_lib:format("~.4w:~.2.0w:~.2.0w-~.2.0w:~.2.0w:~.2.0w.~w", - [YYYY, MM, DD, Hour, Min, Sec, round(N3/1000)]), - lists:flatten(FormatDate). + snmp_misc:formated_timestamp(). + 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(). + -- cgit v1.2.3 From f287e693ef11f0d3fa5dd009154d22d396807325 Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Thu, 11 Apr 2019 12:50:25 +0200 Subject: [snmp|agent|test] Test case info and cleanup 1) A test case failed due to the times retreived by get(snmpEngineTime) reported to large time diffs (this is basically a sanity check). Added some more info about time(s) to see if there are some "gaps" somewhere. The problem occurred on a slow Virtial Machine. 2) A previous (failing) test case failed to cleanup after itself (see above), which caused later test cases to fail. Specifically, the app top supervisor was not terminated, which caused the start agent function to fail (basically already_started). --- lib/snmp/test/snmp_agent_test.erl | 24 +++++++-- lib/snmp/test/snmp_agent_test_lib.erl | 92 +++++++++++++++++++++-------------- 2 files changed, 76 insertions(+), 40 deletions(-) (limited to 'lib') diff --git a/lib/snmp/test/snmp_agent_test.erl b/lib/snmp/test/snmp_agent_test.erl index c4365e6a96..71e3fa3b9a 100644 --- a/lib/snmp/test/snmp_agent_test.erl +++ b/lib/snmp/test/snmp_agent_test.erl @@ -5146,12 +5146,21 @@ snmp_framework_mib_3(Config) when is_list(Config) -> %% Req. SNMP-FRAMEWORK-MIB snmp_framework_mib_test() -> ?line ["agentEngine"] = get_req(1, [[snmpEngineID,0]]), + T1 = snmp_misc:now(ms), ?line [EngineTime] = get_req(2, [[snmpEngineTime,0]]), + T2 = snmp_misc:now(ms), ?SLEEP(5000), + T3 = snmp_misc:now(ms), ?line [EngineTime2] = get_req(3, [[snmpEngineTime,0]]), - ?DBG("snmp_framework_mib -> time(s): " - "~n EngineTime 1 = ~p" - "~n EngineTime 2 = ~p", [EngineTime, EngineTime2]), + T4 = snmp_misc:now(ms), + ?PRINT2("snmp_framework_mib -> time(s): " + "~n EngineTime 1: ~p" + "~n Time to acquire: ~w ms" + "~n EngineTime 2: ~p" + "~n Time to acquire: ~w ms" + "~n => (5 sec sleep between get(snmpEngineTime))" + "~n Total time to acquire: ~w ms", + [EngineTime, T2-T1, EngineTime2, T4-T3, T4-T1]), if (EngineTime+7) < EngineTime2 -> ?line ?FAIL({too_large_diff, EngineTime, EngineTime2}); @@ -5160,11 +5169,18 @@ snmp_framework_mib_test() -> true -> ok end, + T5 = snmp_misc:now(ms), ?line case get_req(4, [[snmpEngineBoots,0]]) of [Boots] when is_integer(Boots) -> + T6 = snmp_misc:now(ms), + ?PRINT2("snmp_framework_mib -> " + "~n boots: ~p" + "~n Time to acquire: ~w ms", [Boots, T6-T5]), ok; Else -> - ?FAIL(Else) + ?PRINT2("snmp_framework_mib -> failed get proper boots:" + "~n ~p", [Else]), + ?FAIL({invalid_boots, Else}) end, ok. diff --git a/lib/snmp/test/snmp_agent_test_lib.erl b/lib/snmp/test/snmp_agent_test_lib.erl index 70e2e5f235..6defdadb5a 100644 --- a/lib/snmp/test/snmp_agent_test_lib.erl +++ b/lib/snmp/test/snmp_agent_test_lib.erl @@ -472,20 +472,24 @@ start_agent(Config, Vsns, Opts) -> process_flag(trap_exit,true), + ?PRINT2("start_agent -> try start snmp app supervisor", []), {ok, AppSup} = snmp_app_sup:start_link(), unlink(AppSup), ?DBG("start_agent -> snmp app supervisor: ~p", [AppSup]), - ?DBG("start_agent -> start master agent",[]), + ?PRINT2("start_agent -> try start master agent",[]), ?line Sup = start_sup(Env), - - ?DBG("start_agent -> unlink from supervisor", []), ?line unlink(Sup), + ?DBG("start_agent -> snmp supervisor: ~p", [Sup]), + + ?PRINT2("start_agent -> try (rpc) start sub agent on ~p", [SaNode]), ?line SaDir = ?config(sa_dir, Config), - ?DBG("start_agent -> (rpc) start sub on ~p", [SaNode]), ?line {ok, Sub} = start_sub_sup(SaNode, SaDir), - ?DBG("start_agent -> done",[]), - ?line [{snmp_sup, {Sup, self()}}, {snmp_sub, Sub} | Config]. + ?DBG("start_agent -> done", []), + + ?line [{snmp_app_sup, AppSup}, + {snmp_sup, {Sup, self()}}, + {snmp_sub, Sub} | Config]. app_agent_env_init(Env0, Opts) -> @@ -678,35 +682,52 @@ merge_agent_options([{Key, _Value} = Opt|Opts], Options) -> stop_agent(Config) when is_list(Config) -> - ?LOG("stop_agent -> entry with" - "~n Config: ~p",[Config]), - - {Sup, Par} = ?config(snmp_sup, Config), - ?DBG("stop_agent -> attempt to stop (sup) ~p" - "~n Sup: ~p" - "~n Par: ~p", - [Sup, - (catch process_info(Sup)), - (catch process_info(Par))]), - - _Info = agent_info(Sup), - ?DBG("stop_agent -> Agent info: " - "~n ~p", [_Info]), - - stop_sup(Sup, Par), - - {Sup2, Par2} = ?config(snmp_sub, Config), - ?DBG("stop_agent -> attempt to stop (sub) ~p" - "~n Sup2: ~p" - "~n Par2: ~p", - [Sup2, - (catch process_info(Sup2)), - (catch process_info(Par2))]), - stop_sup(Sup2, Par2), - - ?DBG("stop_agent -> done - now cleanup config", []), - C1 = lists:keydelete(snmp_sup, 1, Config), - lists:keydelete(snmp_sub, 1, C1). + ?PRINT2("stop_agent -> entry with" + "~n Config: ~p",[Config]), + + + %% Stop the sub-agent (the agent supervisor) + {SubSup, SubPar} = ?config(snmp_sub, Config), + ?PRINT2("stop_agent -> attempt to stop sub agent (~p)" + "~n Sub Sup info: " + "~n ~p" + "~n Sub Par info: " + "~n ~p", + [SubSup, + (catch process_info(SubSup)), + (catch process_info(SubPar))]), + stop_sup(SubSup, SubPar), + Config2 = lists:keydelete(snmp_sub, 1, Config), + + + %% Stop the master-agent (the top agent supervisor) + {MasterSup, MasterPar} = ?config(snmp_sup, Config), + ?PRINT2("stop_agent -> attempt to stop master agent (~p)" + "~n Master Sup: " + "~n ~p" + "~n Master Par: " + "~n ~p" + "~n Agent Info: " + "~n ~p", + [MasterSup, + (catch process_info(MasterSup)), + (catch process_info(MasterPar)), + agent_info(MasterSup)]), + stop_sup(MasterSup, MasterPar), + Config3 = lists:keydelete(snmp_sup, 1, Config2), + + + %% Stop the top supervisor (of the snmp app) + AppSup = ?config(snmp_app_sup, Config), + ?PRINT2("stop_agent -> attempt to app sup ~p" + "~n App Sup: ~p", + [AppSup, + (catch process_info(AppSup))]), + Config4 = lists:keydelete(snmp_app_sup, 1, Config3), + + + ?PRINT2("stop_agent -> done", []), + Config4. start_sup(Env) -> @@ -736,7 +757,6 @@ stop_sup(Pid, _) -> ?LOG("stop_sup -> attempt to stop ~p", [Pid]), Ref = erlang:monitor(process, Pid), ?LOG("stop_sup -> Ref: ~p", [Ref]), - %% Pid ! {'EXIT', Parent, shutdown}, % usch exit(Pid, kill), await_stopped(Pid, Ref). -- cgit v1.2.3 From 675c62ea062a57b2d8fb54a7dc3cbdc799c99823 Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Thu, 11 Apr 2019 19:06:40 +0200 Subject: [snmp] Post rebase fixup --- lib/snmp/src/agent/snmpa_agent.erl | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'lib') diff --git a/lib/snmp/src/agent/snmpa_agent.erl b/lib/snmp/src/agent/snmpa_agent.erl index 1dd989e113..f280260f47 100644 --- a/lib/snmp/src/agent/snmpa_agent.erl +++ b/lib/snmp/src/agent/snmpa_agent.erl @@ -2574,7 +2574,7 @@ process_pdu(#pdu{type = 'get-next-request', request_id = ReqId, varbinds = Vbs}, "~n ReqId: ~p" "~n Vbs: ~p" "~n MibView: ~p", [ReqId, Vbs, MibView]), - OrigRes = do_get_next(MibView, Vbs, infinity), + OrigRes = do_get_next(MibView, Vbs), Res = get_err(OrigRes), {ErrStatus, ErrIndex, ResVarbinds} = if -- cgit v1.2.3