Permalink
Browse files

Bug 950: refactoring, EUnit tests, new config knob

Refactored the code so that it's possible to export a couple of
useful functions, format_event/3 and limited_fmt/4.  The refactoring
also made Eunit tests for the formatting much easier to write.

See the Edoc at the head of riak_err_app.erl for descriptions of
console_error_type and console_sasl_reports.
  • Loading branch information...
1 parent 0435a7b commit 7f2a00d53d930710d82a5982143cfea7ac353327 @slfritchie slfritchie committed Dec 23, 2010
Showing with 156 additions and 37 deletions.
  1. +11 −0 src/riak_err_app.erl
  2. +145 −37 src/riak_err_handler.erl
View
@@ -77,6 +77,17 @@
%% <li> <tt>fmt_max_bytes</tt> When formatting a log-related term that might
%% be "big", limit the term's formatted output to a maximum of
%% <tt>fmt_max_bytes</tt> bytes. The default is 12KBytes. </li>
+%%
+%% <li> <tt>console_error_type</tt> Defines the
+%% handler's choices for writing formatted events to the console/tty.
+%% config values are not quite the same as the <tt>sasl</tt> application's
+%% <tt>errlog_type</tt> parameter: only <tt>error</tt> and <tt>all</tt>
+%% are valid. The default is <tt>all</tt>. </li>
+%%
+%% <li> <tt>console_sasl_reports</tt> Defines whether or not SASL
+%% reports are written to the console/tty. Valid values are Erlang
+%% boolean values. The default is <tt>false</tt>. </li>
+%%
%% </ol>
%%
%% For example, <tt>erl -riak_err term_max_size 8192 fmt_max_bytes 9000</tt>.
View
@@ -36,18 +36,15 @@
%% losing log file entries or worrying about sending a
%% SIGHUP signal to the owner process before rotation. </li>
%% </ul>
-%%
-%% A new environment configuration variable, the <tt>riak_err</tt>
-%% application's <tt>console_error_type</tt> parameter, defines the
-%% handler's choices for writing formatted events to the console/tty.
-%% config values are not quite the same as the <tt>sasl</tt> application's
-%% <tt>errlog_type</tt> parameter: only <tt>error</tt> and <tt>all</tt>
-%% are valid and <tt>all</tt> is the default.
-module(riak_err_handler).
-behaviour(gen_event).
+-ifdef(TEST).
+-include_lib("eunit/include/eunit.hrl").
+-endif.
+
-define(SUPERVISOR_REPORT, "SUPERVISOR REPORT").
-define(CRASH_REPORT, "CRASH REPORT").
-define(PROGRESS_REPORT, "PROGRESS REPORT").
@@ -61,13 +58,17 @@
-export([init/1, handle_event/2, handle_call/2, handle_info/2, terminate/2,
code_change/3]).
+%% Functions perhaps useful to the wider Erlang world.
+-export([format_event/3, limited_fmt/4]).
+
-record(state, {
term_max_size :: pos_integer(),
fmt_max_bytes :: pos_integer(),
log_path :: undefined | string(),
log_fh :: undefined | file:io_device(),
errlog_type :: error | progress | all,
- conslog_type :: error | all
+ conslog_type :: error | all,
+ conslog_sasl :: boolean()
}).
%%%----------------------------------------------------------------------
@@ -126,12 +127,14 @@ init([]) ->
_ -> all
end,
ConslogType = get_env_or_arg(console_error_type, all),
+ ConslogSASL = get_env_or_arg(console_sasl_reports, false),
{ok, #state{term_max_size = TermMaxSize,
fmt_max_bytes = FmtMaxBytes,
log_path = LogPath,
log_fh = LogFH,
errlog_type = ErrlogType,
- conslog_type = ConslogType}}.
+ conslog_type = ConslogType,
+ conslog_sasl = ConslogSASL}}.
%%----------------------------------------------------------------------
%% Func: handle_event/2
@@ -141,10 +144,16 @@ init([]) ->
%%----------------------------------------------------------------------
-spec handle_event({atom(), pid(), {pid(), string() | atom(), any()}}, #state{}) -> {ok, #state{}}.
handle_event(Event, #state{errlog_type = ErrlogType, conslog_type = ConslogType,
- log_fh = LogFH} = State) ->
- {ErrorP, ReportStr, Formatted} = format_event(Event, State),
- case {is_sasl_reportstr(ReportStr), should_log_it(ConslogType, ErrorP, x)} of
- {false, true} ->
+ log_fh = LogFH, term_max_size = TermMaxSize,
+ fmt_max_bytes = FmtMaxBytes,
+ conslog_sasl = ConslogSASL} = State) ->
+ {ErrorP, ReportStr, Formatted} =
+ format_event(Event, TermMaxSize, FmtMaxBytes),
+ case {is_sasl_reportstr(ReportStr), ConslogSASL,
+ should_log_it(ConslogType, ErrorP, x)} of
+ {true, true, true} ->
+ io:put_chars(Formatted);
+ {false, _, true} ->
io:put_chars(Formatted);
_ ->
ok
@@ -210,38 +219,45 @@ code_change(_OldVsn, State, _Extra) ->
%%% Internal functions
%%%----------------------------------------------------------------------
-format_event(Event, S) ->
+-spec format_event(tuple(), integer(), integer()) ->
+ {boolean(), string(), iolist()}.
+%% @doc Given an error_logger-style Event tuple, format it with the
+%% constraints of TermMaxSize and FmtMaxSize.
+%%
+%% See limited_fmt/3 for the meaning of TermMaxSize and FmtMaxSize.
+
+format_event(Event, TermMaxSize, FmtMaxBytes) ->
%% Case clauses appear the same order as error_logger_tty_h:write_event/1.
{ReportStr, Pid, MsgStr, ErrorP} =
case Event of
{_Type, GL, _Msg} when node(GL) /= node() ->
{ignore, ignore, ignore, false};
{error, _GL, {Pid1, Fmt, Args}} ->
- {"ERROR REPORT", Pid1, limited_fmt(Fmt, Args, S), true};
+ {"ERROR REPORT", Pid1, limited_fmt(Fmt, Args, TermMaxSize, FmtMaxBytes), true};
%% SLF: non-standard string below.
{emulator, _GL, Chars} ->
- {"ERROR REPORT", emulator, Chars, false};
+ {"ERROR REPORT", emulator, Chars, true};
{info, _GL, {Pid1, Info, _}} ->
- {"INFO REPORT", Pid1, limited_str(Info, S), false};
+ {"INFO REPORT", Pid1, limited_str(Info, FmtMaxBytes), false};
{error_report, _GL, {Pid1, std_error, Rep}} ->
- {"ERROR REPORT", Pid1, limited_str(Rep, S), true};
+ {"ERROR REPORT", Pid1, limited_str(Rep, FmtMaxBytes), true};
{error_report, _GL, Other} ->
- perhaps_a_sasl_report(error_report, Other, S);
+ perhaps_a_sasl_report(error_report, Other, FmtMaxBytes);
{info_report, _GL, {Pid1, std_info, Rep}} ->
- {"INFO REPORT", Pid1, limited_str(Rep, S), false};
+ {"INFO REPORT", Pid1, limited_str(Rep, FmtMaxBytes), false};
{info_report, _GL, Other} ->
- perhaps_a_sasl_report(info_report, Other, S);
+ perhaps_a_sasl_report(info_report, Other, FmtMaxBytes);
{info_msg, _GL, {Pid1, Fmt, Args}} ->
- {"INFO REPORT", Pid1, limited_fmt(Fmt, Args, S), false};
+ {"INFO REPORT", Pid1, limited_fmt(Fmt, Args, TermMaxSize, FmtMaxBytes), false};
{warning_report, _GL, {Pid1, std_warning, Rep}} ->
- {"WARNING REPORT", Pid1, limited_str(Rep, S), true};
+ {"WARNING REPORT", Pid1, limited_str(Rep, FmtMaxBytes), true};
{warning_report, _GL, _Other} ->
{ignore, ignore, ignore, false};
{warning_msg, _GL, {Pid1, Fmt, Args}} ->
- {"WARNING REPORT", Pid1, limited_fmt(Fmt, Args, S), true};
+ {"WARNING REPORT", Pid1, limited_fmt(Fmt, Args, TermMaxSize, FmtMaxBytes), true};
%% This type is allegedly ignored, so whatever.
_E ->
- {"ODD REPORT", "blahblah", limited_fmt("odd ~p", [_E], S), false}
+ {"ODD REPORT", "blahblah", limited_fmt("odd ~p", [_E], TermMaxSize, FmtMaxBytes), false}
end,
if ReportStr == ignore ->
{false, "", ""};
@@ -252,8 +268,15 @@ format_event(Event, S) ->
[Time, MsgStr, NodeSuffix])}
end.
-limited_fmt(Fmt, Args, #state{fmt_max_bytes = FmtMaxBytes,
- term_max_size = TermMaxSize}) ->
+-spec limited_fmt(string(), list(), integer(), integer()) -> iolist().
+%% @doc Format Fmt and Args similar to what io_lib:format/2 does but with
+%% limits on how large the formatted string may be.
+%%
+%% If the Args list's size is larger than TermMaxSize, then the
+%% formatting is done by trunc_io:print/2, where FmtMaxBytes is used
+%% to limit the formatted string's size.
+
+limited_fmt(Fmt, Args, TermMaxSize, FmtMaxBytes) ->
TermSize = erts_debug:flat_size(Args),
if TermSize > TermMaxSize ->
{Str, _} = trunc_io:print(Args, FmtMaxBytes),
@@ -262,28 +285,28 @@ limited_fmt(Fmt, Args, #state{fmt_max_bytes = FmtMaxBytes,
io_lib:format(Fmt, Args)
end.
-limited_str(Term, S) ->
- {Str, _} = trunc_io:print(Term, S#state.fmt_max_bytes),
+limited_str(Term, FmtMaxBytes) ->
+ {Str, _} = trunc_io:print(Term, FmtMaxBytes),
Str.
other_node_suffix(Pid) when node(Pid) =/= node() ->
"** at node " ++ atom_to_list(node(Pid)) ++ " **\n";
other_node_suffix(_) ->
"".
-perhaps_a_sasl_report(error_report, {Pid, Type, Report}, S) ->
+perhaps_a_sasl_report(error_report, {Pid, Type, Report}, FmtMaxBytes) ->
case riak_err_stdlib:is_my_error_report(Type) of
true ->
{sasl_type_to_report_head(Type), Pid,
- sasl_limited_str(Type, Report, S), true};
+ sasl_limited_str(Type, Report, FmtMaxBytes), true};
false ->
{ignore, ignore, ignore, false}
end;
-perhaps_a_sasl_report(info_report, {Pid, Type, Report}, S) ->
+perhaps_a_sasl_report(info_report, {Pid, Type, Report}, FmtMaxBytes) ->
case riak_err_stdlib:is_my_info_report(Type) of
true ->
{sasl_type_to_report_head(Type), Pid,
- sasl_limited_str(Type, Report, S), false};
+ sasl_limited_str(Type, Report, FmtMaxBytes), false};
false ->
{ignore, ignore, ignore, false}
end;
@@ -297,8 +320,7 @@ sasl_type_to_report_head(crash_report) ->
sasl_type_to_report_head(progress) ->
?PROGRESS_REPORT.
-sasl_limited_str(supervisor_report, Report,
- #state{fmt_max_bytes = FmtMaxBytes}) ->
+sasl_limited_str(supervisor_report, Report, FmtMaxBytes) ->
Name = riak_err_stdlib:sup_get(supervisor, Report),
Context = riak_err_stdlib:sup_get(errorContext, Report),
Reason = riak_err_stdlib:sup_get(reason, Report),
@@ -308,12 +330,12 @@ sasl_limited_str(supervisor_report, Report,
{ReasonStr, _} = trunc_io:print(Reason, FmtMaxBytes),
{OffenderStr, _} = trunc_io:print(Offender, FmtMaxBytes),
io_lib:format(FmtString, [Name, Context, ReasonStr, OffenderStr]);
-sasl_limited_str(progress, Report, #state{fmt_max_bytes = FmtMaxBytes}) ->
+sasl_limited_str(progress, Report, FmtMaxBytes) ->
[begin
{Str, _} = trunc_io:print(Data, FmtMaxBytes),
io_lib:format(" ~16w: ~s~n", [Tag, Str])
end || {Tag, Data} <- Report];
-sasl_limited_str(crash_report, Report, #state{fmt_max_bytes = FmtMaxBytes}) ->
+sasl_limited_str(crash_report, Report, FmtMaxBytes) ->
riak_err_stdlib:proc_lib_format(Report, FmtMaxBytes).
get_int_env(Name, Default) ->
@@ -370,3 +392,89 @@ is_sasl_reportstr(?PROGRESS_REPORT) ->
true;
is_sasl_reportstr(_) ->
false.
+
+-ifdef(TEST).
+
+format_event_test() ->
+ Nd = node(),
+ P = self(),
+ Own = [{own, foo}, {bar, baz}],
+ Link = [{link, foo2}, {bar2, baz2}],
+
+ {false, "ODD REPORT", _} = fe_wrap({foo, asdf, asdf}, 1024, 1024),
+ {true, "ERROR REPORT", _} =
+ fe_wrap({error, Nd, {P, "~s", ["!"]}},
+ 1024, 1024),
+ {true, "ERROR REPORT", _} =
+ fe_wrap({emulator, Nd, "!"},
+ 1024, 1024),
+ {true, "ERROR REPORT", _} =
+ fe_wrap({error_report, Nd, {P, std_error, ["report!"]}},
+ 1024, 1024),
+ {true, ?SUPERVISOR_REPORT, _} =
+ fe_wrap({error_report, Nd, {P, supervisor_report, ["report!"]}},
+ 1024, 1024),
+ {true, ?CRASH_REPORT, _} =
+ fe_wrap({error_report, Nd, {P, crash_report, [Own, Link]}},
+ 1024, 1024),
+ {false, _, _} =
+ fe_wrap({error_report, Nd, {P, someone_else_report, ["report!"]}},
+ 1024, 1024),
+ {false, "INFO REPORT", _} =
+ fe_wrap({info_report, Nd, {P, std_info, ["report!"]}},
+ 1024, 1024),
+ {false, ?PROGRESS_REPORT, _} =
+ fe_wrap({info_report, Nd, {P, progress, ["report!"]}},
+ 1024, 1024),
+ {false, _, _} =
+ fe_wrap({info_report, Nd, {P, someone_else_report, ["report!"]}},
+ 1024, 1024),
+ {false, "INFO REPORT", _} =
+ fe_wrap({info_msg, Nd, {P, "~s", ["!"]}},
+ 1024, 1024),
+ {true, "WARNING REPORT", _} =
+ fe_wrap({warning_report, Nd, {P, std_warning, ["report!"]}},
+ 1024, 1024),
+ {false, _, _} =
+ fe_wrap({error_report, Nd, {P, someone_else_report, ["report!"]}},
+ 1024, 1024),
+ {true, "WARNING REPORT", _} =
+ fe_wrap({warning_msg, Nd, {P, "~s", ["!"]}},
+ 1024, 1024),
+ {false, "ODD REPORT", _} =
+ fe_wrap({moo},
+ 1024, 1024),
+
+ %% Check that the truncation flavors are all working
+ Word = "YOYOYO",
+ Atom = foo,
+ LongStr = "Here's a big string with a sentinel word at the end: " ++ Word,
+ {true, _, Str1} = fe_wrap({error, Nd, {P, "atom ~p, string ~s\n",
+ [Atom, LongStr]}},
+ 1024, 1024),
+ nomatch = re:run(Str1, "Oversize"),
+ {match, _} = re:run(Str1, Word),
+ {true, _, Str2} = fe_wrap({error, Nd, {P, "atom ~p, string ~s\n",
+ [Atom, LongStr]}},
+ 20, 1024),
+ {match, _} = re:run(Str2, "Oversize"),
+ {match, _} = re:run(Str2, Word),
+ {true, _, Str3} = fe_wrap({error, Nd, {P, "atom ~p, string ~s\n",
+ [Atom, LongStr]}},
+ 20, 20),
+ {match, _} = re:run(Str3, "Oversize"),
+ nomatch = re:run(Str3, Word),
+ {true, _, Str4} = fe_wrap({error, Nd, {P, "atom ~p, string ~s\n",
+ [Atom, LongStr]}},
+ 1024, 20),
+ nomatch = re:run(Str4, "Oversize"),
+ {match, _} = re:run(Str4, Word),
+
+ %% [io:format(user, "Res: ~s\n", [XX]) || XX <- [Str1, Str2, Str3, Str4]],
+ ok.
+
+fe_wrap(A, B, C) ->
+ {X, Y, Z} = format_event(A, B, C),
+ {X, Y, lists:flatten(Z)}.
+
+-endif. % TEST

0 comments on commit 7f2a00d

Please sign in to comment.