From 7c0333ff7a559c2d0f138b3156c4a5b73e15051b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Fri, 21 Aug 2015 10:54:00 +0200 Subject: Teach error_logger_file_h to truncate big messages Add the possibility to truncate big messages to avoid running out of memory. --- lib/stdlib/test/error_logger_h_SUITE.erl | 145 +++++++++++++++++++++---------- 1 file changed, 99 insertions(+), 46 deletions(-) (limited to 'lib/stdlib/test') diff --git a/lib/stdlib/test/error_logger_h_SUITE.erl b/lib/stdlib/test/error_logger_h_SUITE.erl index cd0d3a511e..7cde659b9f 100644 --- a/lib/stdlib/test/error_logger_h_SUITE.erl +++ b/lib/stdlib/test/error_logger_h_SUITE.erl @@ -20,7 +20,7 @@ -module(error_logger_h_SUITE). -export([all/0, suite/0,groups/0,init_per_suite/1, end_per_suite/1, init_per_group/2,end_per_group/2]). --export([logfile/1,tty/1]). +-export([logfile/1,logfile_truncated/1,tty/1]). %% Event handler exports. -export([init/1,handle_event/2,terminate/2]). @@ -30,7 +30,7 @@ suite() -> [{ct_hooks,[ts_install_cth]}]. all() -> - [logfile,tty]. + [logfile,logfile_truncated,tty]. groups() -> []. @@ -55,10 +55,7 @@ logfile(Config) -> Ev = event_templates(), - error_logger:logfile({open,Log}), - gen_events(Ev), - error_logger:logfile(close), - analyse_events(Log, Ev, []), + do_one_logfile(Log, Ev, unlimited), Pa = "-pa " ++ filename:dirname(code:which(?MODULE)), {ok,Node} = start_node(logfile, Pa), @@ -66,13 +63,38 @@ logfile(Config) -> ok = rpc:call(Node, erlang, apply, [fun gen_events/1,[Ev]]), AtNode = iolist_to_binary(["** at node ",atom_to_list(Node)," **"]), error_logger:logfile(close), - analyse_events(Log, Ev, [AtNode]), + analyse_events(Log, Ev, [AtNode], unlimited), test_server:stop_node(Node), cleanup(Log), ok. +logfile_truncated(Config) -> + PrivDir = ?config(priv_dir, Config), + LogDir = filename:join(PrivDir, ?MODULE), + Log = filename:join(LogDir, "logfile_truncated.log"), + ok = filelib:ensure_dir(Log), + + Ev = event_templates(), + + Depth = 20, + application:set_env(kernel, error_logger_format_depth, Depth), + try + do_one_logfile(Log, Ev, Depth) + after + application:unset_env(kernel, error_logger_format_depth) + end, + + cleanup(Log), + ok. + +do_one_logfile(Log, Ev, Depth) -> + error_logger:logfile({open,Log}), + gen_events(Ev), + error_logger:logfile(close), + analyse_events(Log, Ev, [], Depth). + tty(Config) -> PrivDir = ?config(priv_dir, Config), LogDir = filename:join(PrivDir, ?MODULE), @@ -81,10 +103,7 @@ tty(Config) -> Ev = event_templates(), - tty_log_open(Log), - gen_events(Ev), - tty_log_close(), - analyse_events(Log, Ev, []), + do_one_tty(Log, Ev, unlimited), Pa = "-pa " ++ filename:dirname(code:which(?MODULE)), {ok,Node} = start_node(logfile, Pa), @@ -92,13 +111,19 @@ tty(Config) -> ok = rpc:call(Node, erlang, apply, [fun gen_events/1,[Ev]]), tty_log_close(), AtNode = iolist_to_binary(["** at node ",atom_to_list(Node)," **"]), - analyse_events(Log, Ev, [AtNode]), + analyse_events(Log, Ev, [AtNode], unlimited), test_server:stop_node(Node), cleanup(Log), ok. +do_one_tty(Log, Ev, Depth) -> + tty_log_open(Log), + gen_events(Ev), + tty_log_close(), + analyse_events(Log, Ev, [], Depth). + tty_log_open(Log) -> {ok,Fd} = file:open(Log, [write]), error_logger:add_report_handler(?MODULE, Fd), @@ -134,7 +159,14 @@ event_templates() -> {warning_report,[warning_atom]}, {warning_report,["warning string"]}, - {warning_report,[[{warning_tag,value},warning_value]]}]. + {warning_report,[[{warning_tag,value},warning_value]]}, + + %% Bigger terms. + {error_msg,["fairly big: ~p\n",[lists:seq(1, 128)]]}, + {error_report,[list_to_tuple(lists:seq(1, 100))]}, + {error_report,[lists:seq(32, 126)]}, + {error_report,[[{tag,lists:seq(1, 64)}]]} + ]. gen_events(Ev) -> io:format("node = ~p\n", [node()]), @@ -155,7 +187,7 @@ gen_events(Ev) -> receive after 100 -> ok end, ok. -analyse_events(Log, Ev, AtNode) -> +analyse_events(Log, Ev, AtNode, Depth) -> {ok,Bin} = file:read_file(Log), io:format("*** Contents of log file ***\n\n~s\n", [Bin]), @@ -163,7 +195,7 @@ analyse_events(Log, Ev, AtNode) -> Lines = binary:split(Bin, <<"\n">>, [global,trim_all]), io:format("~p\n", [Lines]), - Rest = match_output(Ev, Lines, AtNode), + Rest = match_output(Ev, Lines, AtNode, Depth), io:format("~p\n", [Rest]), [] = match_emulator_error(Rest), @@ -184,10 +216,10 @@ match_emulator_error([Head,Second,Third,_|Lines]) -> {match,[{0,_}]} = re:run(Third, "^[{]ouch,"), Lines. -match_output([Item|T], Lines0, AtNode) -> - try match_item(Item, Lines0, AtNode) of +match_output([Item|T], Lines0, AtNode, Depth) -> + try match_item(Item, Lines0, AtNode, Depth) of Lines -> - match_output(T, Lines, AtNode) + match_output(T, Lines, AtNode, Depth) catch C:E -> Stk = erlang:get_stacktrace(), @@ -195,14 +227,14 @@ match_output([Item|T], Lines0, AtNode) -> io:format("LINES: ~p", [Lines0]), erlang:raise(C, E, Stk) end; -match_output([], Lines, _) -> Lines. +match_output([], Lines, _, _) -> Lines. -match_item(Item, Lines, AtNode) -> +match_item(Item, Lines, AtNode, Depth) -> case item_type(Item) of {msg,Head,Args} -> - match_format(Head, Args, Lines, AtNode); + match_format(Head, Args, Lines, AtNode, Depth); {report,Head,Args} -> - match_term(Head, Args, Lines, AtNode) + match_term(Head, Args, Lines, AtNode, Depth) end. item_type({error_msg,Args}) -> @@ -218,46 +250,46 @@ item_type({info_report,Args}) -> item_type({warning_report,Args}) -> {report,<<"WARNING">>,Args}. -match_format(Tag, [Format,Args], [Head|Lines], AtNode) -> +match_format(Tag, [Format,Args], [Head|Lines], AtNode, Depth) -> match_head(Tag, Head), - Bin = try io_lib:format(Format, Args) of + Bin = try dl_format(Depth, Format, Args) of Str -> iolist_to_binary(Str) catch _:_ -> - S = io_lib:format("ERROR: ~p - ~p~n", [Format,Args]), + S = dl_format(Depth, "ERROR: ~p - ~p~n", [Format,Args]), iolist_to_binary(S) end, - Expected0 = binary:split(Bin, <<"\n">>, [trim_all]), + Expected0 = binary:split(Bin, <<"\n">>, [global,trim]), Expected = Expected0 ++ AtNode, match_term_lines(Expected, Lines). -match_term(Tag, [Arg], [Head|Lines], AtNode) -> +match_term(Tag, [Arg], [Head|Lines], AtNode, Depth) -> match_head(Tag, Head), - Expected0 = match_term_get_expected(Arg), + Expected0 = match_term_get_expected(Arg, Depth), Expected = Expected0 ++ AtNode, match_term_lines(Expected, Lines). -match_term_get_expected(List) when is_list(List) -> - try iolist_to_binary(List) of - Bin -> - [Bin] - catch - _:_ -> - format_rep(List) - end; -match_term_get_expected(Term) -> - S = io_lib:format("~p", [Term]), +match_term_get_expected(List, Depth) when is_list(List) -> + Bin = try iolist_to_binary(dl_format(Depth, "~s\n", [List])) of + Bin0 -> Bin0 + catch + _:_ -> + iolist_to_binary(format_rep(List, Depth)) + end, + binary:split(Bin, <<"\n">>, [global,trim]); +match_term_get_expected(Term, Depth) -> + S = dl_format(Depth, "~p\n", [Term]), Bin = iolist_to_binary(S), - [Bin]. + binary:split(Bin, <<"\n">>, [global,trim]). -format_rep([{Tag,Data}|Rep]) -> - [iolist_to_binary(io_lib:format(" ~p: ~p", [Tag,Data]))| - format_rep(Rep)]; -format_rep([Other|Rep]) -> - [iolist_to_binary(io_lib:format(" ~p", [Other]))| - format_rep(Rep)]; -format_rep([]) -> []. +format_rep([{Tag,Data}|Rep], Depth) -> + [dl_format(Depth, " ~p: ~p\n", [Tag,Data])| + format_rep(Rep, Depth)]; +format_rep([Other|Rep], Depth) -> + [dl_format(Depth, " ~p\n", [Other])| + format_rep(Rep, Depth)]; +format_rep([], _Depth) -> []. match_term_lines([Line|T], [Line|Lines]) -> match_term_lines(T, Lines); @@ -298,6 +330,27 @@ cleanup(File) -> ok. +%% Depth-limited io_lib:format. Intentionally implemented here instead +%% of using io_lib:scan_format/2 to avoid using the same implementation +%% as in the error_logger handlers. + +dl_format(unlimited, Format, Args) -> + io_lib:format(Format, Args); +dl_format(Depth, Format0, Args0) -> + {Format,Args} = dl_format_1(Format0, Args0, Depth, [], []), + io_lib:format(Format, Args). + +dl_format_1("~p"++Fs, [A|As], Depth, Facc, Acc) -> + dl_format_1(Fs, As, Depth, [$P,$~|Facc], [Depth,A|Acc]); +dl_format_1("~w"++Fs, [A|As], Depth, Facc, Acc) -> + dl_format_1(Fs, As, Depth, [$W,$~|Facc], [Depth,A|Acc]); +dl_format_1("~s"++Fs, [A|As], Depth, Facc, Acc) -> + dl_format_1(Fs, As, Depth, [$s,$~|Facc], [A|Acc]); +dl_format_1([F|Fs], As, Depth, Facc, Aacc) -> + dl_format_1(Fs, As, Depth, [F|Facc], Aacc); +dl_format_1([], [], _, Facc, Aacc) -> + {lists:reverse(Facc),lists:reverse(Aacc)}. + %%% %%% Our own event handler. There is no way to intercept the output %%% from error_logger_tty_h, but we can use the same code by -- cgit v1.2.3