From 947c2a97ad51e1936bad7df0e3f768ab15fcbb36 Mon Sep 17 00:00:00 2001 From: Micael Karlberg Date: Wed, 5 Sep 2018 18:53:15 +0200 Subject: [snmp] Improved Audit Trail Log conversion failure If conversion of an Audit Trail Log (ATL) entry failed, this could result in an abort of the entire conversion, not just the one entry. This has now been improved so that the failure now results in a "error message" into the "stream". Furthermore, we now keep track of the number of entries we succeede and fail to convert. OTP-15287 (ERIERL-206) --- lib/snmp/src/misc/snmp_log.erl | 335 ++++++++++++++++++++++++----------------- 1 file changed, 197 insertions(+), 138 deletions(-) diff --git a/lib/snmp/src/misc/snmp_log.erl b/lib/snmp/src/misc/snmp_log.erl index 767d801eee..d8a0141ec8 100644 --- a/lib/snmp/src/misc/snmp_log.erl +++ b/lib/snmp/src/misc/snmp_log.erl @@ -649,13 +649,14 @@ do_log_to_file(Log, TextFile, Mibs, Start, Stop) -> MiniMib = snmp_mini_mib:create(Mibs), Write = fun(X) -> case format_msg(X, MiniMib, Start, Stop) of - {ok, S} -> - io:format(Fd, "~s", [S]); - _ -> - ok + {Tag, S} when (Tag =:= ok) orelse (Tag =:= error) -> + io:format(Fd, "~s", [S]), + Tag; + X -> + X end end, - Res = (catch loop(disk_log:chunk(Log, start), Log, Write)), + Res = (catch loop(Log, Write)), snmp_mini_mib:delete(MiniMib), file:close(Fd), Res; @@ -668,39 +669,66 @@ do_log_to_io(Log, Mibs, Start, Stop) -> MiniMib = snmp_mini_mib:create(Mibs), Write = fun(X) -> case format_msg(X, MiniMib, Start, Stop) of - {ok, S} -> - io:format("~s", [S]); - _ -> - ok + {Tag, S} when (Tag =:= ok) orelse (Tag =:= error) -> + io:format("~s", [S]), + Tag; + X -> + X end end, - (catch loop(disk_log:chunk(Log, start), Log, Write)), + Res = (catch loop(Log, Write)), snmp_mini_mib:delete(MiniMib), - ok. + Res. + +loop(Log, Write) -> + loop(disk_log:chunk(Log, start), Log, Write, 0, 0). -loop(eof, _Log, _Write) -> +loop(eof, _Log, _Write, _NumOK, 0 = _NumERR) -> ok; -loop({error, _} = Error, _Log, _Write) -> +loop(eof, _Log, _Write, NumOK, NumERR) -> + {ok, {NumOK, NumERR}}; +loop({error, _} = Error, _Log, _Write, _NumOK, _NumERR) -> Error; -loop({Cont, Terms}, Log, Write) -> - case (catch lists:foreach(Write, Terms)) of - {'EXIT', Reason} -> - {error, Reason}; - _ -> - loop(disk_log:chunk(Log, Cont), Log, Write) +loop({Cont, Terms}, Log, Write, NumOK, NumERR) -> + try loop_terms(Terms, Write) of + {ok, {AddedOK, AddedERR}} -> + loop(disk_log:chunk(Log, Cont), Log, Write, + NumOK+AddedOK, NumERR+AddedERR) + catch + T:E -> + {error, {T, E}} end; -loop({Cont, Terms, BadBytes}, Log, Write) -> +loop({Cont, Terms, BadBytes}, Log, Write, NumOK, NumERR) -> error_logger:error_msg("Skipping ~w bytes while converting ~p~n~n", [BadBytes, Log]), - case (catch lists:foreach(Write, Terms)) of - {'EXIT', Reason} -> - {error, Reason}; - _ -> - loop(disk_log:chunk(Log, Cont), Log, Write) - end; -loop(Error, _Log, _Write) -> - Error. + try loop_terms(Terms, Write) of + {ok, {AddedOK, AddedERR}} -> + loop(disk_log:chunk(Log, Cont), Log, Write, + NumOK+AddedOK, NumERR+AddedERR) + catch + T:E -> + {error, {T, E}} + end. + + +loop_terms(Terms, Write) -> + loop_terms(Terms, Write, 0, 0). + +loop_terms([], _Write, NumOK, NumERR) -> + {ok, {NumOK, NumERR}}; +loop_terms([Term|Terms], Write, NumOK, NumERR) -> + try Write(Term) of + ok -> + loop_terms(Terms, Write, NumOK+1, NumERR); + error -> + loop_terms(Terms, Write, NumOK, NumERR+1); + _ -> + loop_terms(Terms, Write, NumOK, NumERR) + catch + T:E:S -> + {error, {T, E, S}} + end. format_msg(Entry, Mib, Start, Stop) -> @@ -733,88 +761,149 @@ do_format_msg({Timestamp, SeqNo, Packet, Ip, Port}, Mib) -> %% This is crap... do_format_msg(_, _) -> - format_tab("** unknown entry in log file\n\n", []). + {error, format_tab("** unknown entry in log file\n\n", [])}. do_format_msg(TimeStamp, {V3Hdr, ScopedPdu}, AddrStr, Mib) -> - case (catch snmp_pdus:dec_scoped_pdu(ScopedPdu)) of + try snmp_pdus:dec_scoped_pdu(ScopedPdu) of ScopedPDU when is_record(ScopedPDU, scopedPdu) -> Msg = #message{version = 'version-3', vsn_hdr = V3Hdr, data = ScopedPDU}, - f(ts2str(TimeStamp), "", Msg, AddrStr, Mib); - {'EXIT', Reason} -> - format_tab( - "** error in log file at ~s from ~s ~p\n\n", - [ts2str(TimeStamp), AddrStr, Reason]) + try f(ts2str(TimeStamp), "", Msg, AddrStr, Mib) of + {ok, _} = OK -> + OK + catch + FormatT:FormatE -> + format_error("format scoped pdu", + TimeStamp, AddrStr, FormatT, FormatE) + end + catch + DecT:DecE -> + format_error("decode scoped pdu", + TimeStamp, AddrStr, DecT, DecE) end; do_format_msg(TimeStamp, Packet, AddrStr, Mib) -> - case (catch snmp_pdus:dec_message(binary_to_list(Packet))) of + try snmp_pdus:dec_message(binary_to_list(Packet)) of Msg when is_record(Msg, message) -> - f(ts2str(TimeStamp), "", Msg, AddrStr, Mib); - {'EXIT', Reason} -> - format_tab("** error in log file ~p\n\n", [Reason]) + try f(ts2str(TimeStamp), "", Msg, AddrStr, Mib) of + {ok, _} = OK -> + OK + catch + FormatT:FormatE -> + %% Provide info about the message + Extra = + case Msg#message.version of + 'version-3' -> + #v3_hdr{msgID = ID, + msgFlags = Flags, + msgSecurityModel = SecModel} = + Msg#message.vsn_hdr, + SecLevel = snmp_misc:get_sec_level(Flags), + f("msg-id: ~w, sec-level: ~w, sec-model: ~w", + [ID, SecLevel, sm2atom(SecModel)]); + _ -> %% Community + f("community: ~s", [Msg#message.vsn_hdr]) + end, + format_error(f("format ~p message; ~s", + [Msg#message.version, Extra]), + TimeStamp, AddrStr, FormatT, FormatE) + end + catch + DecT:DecE -> + format_error("decode message", + TimeStamp, AddrStr, DecT, DecE) + end. - + +sm2atom(?SEC_ANY) -> any; +sm2atom(?SEC_V1) -> v1; +sm2atom(?SEC_V2C) -> v2c; +sm2atom(?SEC_USM) -> usm; +sm2atom(_) -> unknown. + do_format_msg(TimeStamp, SeqNo, {V3Hdr, ScopedPdu}, AddrStr, Mib) -> - case (catch snmp_pdus:dec_scoped_pdu(ScopedPdu)) of + try snmp_pdus:dec_scoped_pdu(ScopedPdu) of ScopedPDU when is_record(ScopedPDU, scopedPdu) -> Msg = #message{version = 'version-3', vsn_hdr = V3Hdr, data = ScopedPDU}, - f(ts2str(TimeStamp), sn2str(SeqNo), Msg, AddrStr, Mib); - {'EXIT', Reason} -> - format_tab( - "** error in log file at ~s from ~s ~p\n\n", - [ts2str(TimeStamp), sn2str(SeqNo), AddrStr, Reason]) + try f(ts2str(TimeStamp), sn2str(SeqNo), Msg, AddrStr, Mib) of + {ok, _} = OK -> + OK + catch + FormatT:FormatE -> + format_error("format scoped pdu", + TimeStamp, SeqNo, AddrStr, FormatT, FormatE) + end + catch + DecT:DecE -> + format_error("decode scoped pdu", + TimeStamp, SeqNo, AddrStr, DecT, DecE) end; do_format_msg(TimeStamp, SeqNo, Packet, AddrStr, Mib) -> - case (catch snmp_pdus:dec_message(binary_to_list(Packet))) of + try snmp_pdus:dec_message(binary_to_list(Packet)) of Msg when is_record(Msg, message) -> - f(ts2str(TimeStamp), sn2str(SeqNo), Msg, AddrStr, Mib); - {'EXIT', Reason} -> - format_tab( - "** error in log file ~s from ~s ~p\n\n", - [ts2str(TimeStamp), sn2str(SeqNo), AddrStr, Reason]) + try f(ts2str(TimeStamp), sn2str(SeqNo), Msg, AddrStr, Mib) of + {ok, _} = OK -> + OK + + catch + FormatT:FormatE -> + %% Provide info about the message + Extra = + case Msg#message.version of + 'version-3' -> + #v3_hdr{msgID = ID, + msgFlags = Flags, + msgSecurityModel = SecModel} = + Msg#message.vsn_hdr, + SecLevel = snmp_misc:get_sec_level(Flags), + f("msg-id: ~w, sec-level: ~w, sec-model: ~w", + [ID, SecLevel, sm2atom(SecModel)]); + _ -> %% Community + f("community: ~s", [Msg#message.vsn_hdr]) + end, + format_error(f("format ~p message; ~s", + [Msg#message.version, Extra]), + TimeStamp, SeqNo, AddrStr, FormatT, FormatE) + end + catch + DecT:DecE -> + format_error("decode message", + TimeStamp, SeqNo, AddrStr, DecT, DecE) end. - - -%% format_msg({TimeStamp, {V3Hdr, ScopedPdu}, {Addr, Port}}, -%% Mib, Start, Stop) -> -%% format_msg({TimeStamp, {V3Hdr, ScopedPdu}, Addr, Port}, -%% Mib, Start, Stop); -%% format_msg({TimeStamp, {V3Hdr, ScopedPdu}, Addr, Port}, -%% Mib, Start, Stop) -> -%% case timestamp_filter(TimeStamp, Start, Stop) of -%% true -> -%% case (catch snmp_pdus:dec_scoped_pdu(ScopedPdu)) of -%% ScopedPDU when record(ScopedPDU, scopedPdu) -> -%% Msg = #message{version = 'version-3', -%% vsn_hdr = V3Hdr, -%% data = ScopedPDU}, -%% f(ts2str(TimeStamp), Msg, Addr, Port, Mib); -%% {'EXIT', Reason} -> -%% format_tab("** error in log file at ~s from ~p:~w ~p\n\n", -%% [ts2str(TimeStamp), ip(Addr), Port, Reason]) -%% end; -%% false -> -%% ignore -%% end; -%% format_msg({TimeStamp, Packet, {Addr, Port}}, Mib, Start, Stop) -> -%% format_msg({TimeStamp, Packet, Addr, Port}, Mib, Start, Stop); -%% format_msg({TimeStamp, Packet, Addr, Port}, Mib, Start, Stop) -> -%% case timestamp_filter(TimeStamp, Start, Stop) of -%% true -> -%% case (catch snmp_pdus:dec_message(binary_to_list(Packet))) of -%% Msg when record(Msg, message) -> -%% f(ts2str(TimeStamp), Msg, Addr, Port, Mib); -%% {'EXIT', Reason} -> -%% format_tab("** error in log file ~p\n\n", [Reason]) -%% end; -%% false -> -%% ignore -%% end; -%% format_msg(_, _Mib, _Start, _Stop) -> -%% format_tab("** unknown entry in log file\n\n", []). + + +format_error(WhatStr, TimeStamp, AddrStr, throw, {error, Reason}) -> + {ok, Str} = + format_tab( + "** error (~s) in log file at ~s from ~s: " + "~n ~p\n\n", + [WhatStr, ts2str(TimeStamp), AddrStr, Reason]), + {error, Str}; +format_error(WhatStr, TimeStamp, AddrStr, T, E) -> + {ok, Str} = + format_tab( + "** error (~s) in log file at ~s from ~s: " + "~n ~w: ~p\n\n", + [WhatStr, ts2str(TimeStamp), AddrStr, T, E]), + {error, Str}. + +format_error(WhatStr, TimeStamp, SeqNo, AddrStr, throw, {error, Reason}) -> + {ok, Str} = + format_tab( + "** error (~s) in log file at ~s~s from ~s: " + "~n ~p\n\n", + [WhatStr, ts2str(TimeStamp), sn2str(SeqNo), AddrStr, Reason]), + {error, Str}; +format_error(WhatStr, TimeStamp, SeqNo, AddrStr, T, E) -> + {ok, Str} = + format_tab( + "** error (~s) in log file at ~s~s from ~s: " + "~n ~w, ~p\n\n", + [WhatStr, ts2str(TimeStamp), sn2str(SeqNo), AddrStr, T, E]), + {error, Str}. + f(TimeStamp, SeqNo, #message{version = Vsn, vsn_hdr = VsnHdr, data = Data}, @@ -838,51 +927,21 @@ f(TimeStamp, SeqNo, end, format_tab( "~w ~s - ~s [~s]~s ~w\n~s", - [Class, AddrStr, HdrStr, TimeStamp, SeqNo, Vsn, Str]). - -%% f(TimeStamp, SeqNo, -%% #message{version = Vsn, vsn_hdr = VsnHdr, data = Data}, -%% Addr, Port, Mib) -> -%% Str = format_pdu(Data, Mib), -%% HdrStr = format_header(Vsn, VsnHdr), -%% case get_type(Data) of -%% trappdu -> -%% f_trap(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port); -%% 'snmpv2-trap' -> -%% f_trap(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port); -%% 'inform-request' -> -%% f_inform(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port); -%% 'get-response' -> -%% f_response(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port); -%% report -> -%% f_report(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port); -%% _ -> -%% f_request(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port) -%% end. - -%% f_request(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port) -> -%% format_tab("request ~s:~w - ~s [~s]~s ~w\n~s", -%% [ip(Addr), Port, HdrStr, TimeStamp, SeqNo, Vsn, Str]). - -%% f_response(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port) -> -%% format_tab("response ~s:~w - ~s [~s]~s ~w\n~s", -%% [ip(Addr), Port, HdrStr, TimeStamp, SeqNo, Vsn, Str]). - -%% f_report(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port) -> -%% format_tab("report ~s:~w - ~s [~s]~s ~w\n~s", -%% [ip(Addr), Port, HdrStr, TimeStamp, SeqNo, Vsn, Str]). + [Class, AddrStr, HdrStr, TimeStamp, SeqNo, Vsn, Str]); +f(TimeStamp, SeqNo, Msg, AddrStr, _Mib) -> + io:format(" Unexpected data: " + "~n TimeStamp: ~s~s" + "~n Msg: ~p" + "~n AddrStr: ~p" + "~n", [TimeStamp, SeqNo, Msg, AddrStr]), + throw({error, 'invalid-message'}). -%% f_trap(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port) -> -%% format_tab("trap ~s:~w - ~s [~s]~s ~w\n~s", -%% [ip(Addr), Port, HdrStr, TimeStamp, SeqNo, Vsn, Str]). +f(F, A) -> + lists:flatten(io_lib:format(F, A)). -%% f_inform(TimeStamp, SeqNo, Vsn, HdrStr, Str, Addr, Port) -> -%% format_tab("inform ~s:~w - ~s [~s]~s ~w\n~s", -%% [ip(Addr), Port, HdrStr, TimeStamp, SeqNo, Vsn, Str]). ipPort2Str(Ip, Port) -> snmp_conf:mk_addr_string({Ip, Port}). - %% io_lib:format("~s:~w", [ip(Ip), Port]). %% Convert a timestamp 2-tupple to a printable string %% @@ -973,7 +1032,13 @@ format_pdu(#scopedPdu{contextName = Context, data = Pdu}, Mib) -> io_lib:format("Context: \"~s\"\n~s", [Context, snmp_misc:format_pdu(Pdu, Mib)]); format_pdu(Pdu, Mib) -> - snmp_misc:format_pdu(Pdu, Mib). + try snmp_misc:format_pdu(Pdu, Mib) of + Str -> + Str + catch + _:_ -> + throw({error, 'invalid-pdu'}) + end. get_type(#scopedPdu{data = Pdu}) -> get_type(Pdu); @@ -983,12 +1048,6 @@ get_type(#pdu{type = Type}) -> Type. -%% ip(Domain, Addr) -> -%% snmp_conf:mk_addr_string(Domain, Addr). -%% ip({A,B,C,D}) -> -%% io_lib:format("~w.~w.~w.~w", [A,B,C,D]). - - %% ------------------------------------------------------------------- %% Various utility functions -- cgit v1.2.3