Teach error_logger_file_h to truncate big messages

Add the possibility to truncate big messages to avoid running out
of memory.

2 files changed, 134 insertions, 51 deletions

diff --git a/lib/stdlib/src/error_logger_file_h.erl b/lib/stdlib/src/error_logger_file_h.erl
index 5f8bf9092a..48c471924e 100644
--- a/lib/stdlib/src/error_logger_file_h.erl
+++ b/lib/stdlib/src/error_logger_file_h.erl
@@ -37,7 +37,8 @@
 -record(st,
 	{fd,
 	 filename,
-	 prev_handler}).
+	 prev_handler,
+	 depth=unlimited :: 'unlimited' | non_neg_integer()}).
 
 %% This one is used when we takeover from the simple error_logger.
 init({File, {error_logger, Buf}}) ->
@@ -56,11 +57,22 @@ init(File, PrevHandler) ->
     process_flag(trap_exit, true),
     case file:open(File, [write]) of
 	{ok,Fd} ->
-	    {ok, #st{fd=Fd,filename=File,prev_handler=PrevHandler}};
+	    Depth = get_depth(),
+	    State = #st{fd=Fd,filename=File,prev_handler=PrevHandler,
+			depth=Depth},
+	    {ok, State};
 	Error ->
 	    Error
     end.
-    
+
+get_depth() ->
+    case application:get_env(kernel, error_logger_format_depth) of
+	{ok, Depth} when is_integer(Depth) ->
+	    max(10, Depth);
+	undefined ->
+	    unlimited
+    end.
+
 handle_event({_Type, GL, _Msg}, State) when node(GL) =/= node() ->
     {ok, State};
 handle_event(Event, State) ->
@@ -123,17 +135,35 @@ write_event(#st{fd=Fd}=State, Event) ->
     end.
 
 format_body(State, [{Format,Args}|T]) ->
-    S = try io_lib:format(Format, Args) of
+    S = try format(State, Format, Args) of
 	    S0 ->
 		S0
 	catch
 	    _:_ ->
-		io_lib:format("ERROR: ~p - ~p\n", [Format,Args])
+		format(State, "ERROR: ~p - ~p\n", [Format,Args])
 	end,
     [S|format_body(State, T)];
 format_body(_State, []) ->
     [].
 
+format(#st{depth=unlimited}, Format, Args) ->
+    io_lib:format(Format, Args);
+format(#st{depth=Depth}, Format0, Args) ->
+    Format1 = io_lib:scan_format(Format0, Args),
+    Format = limit_format(Format1, Depth),
+    io_lib:build_text(Format).
+
+limit_format([#{control_char:=C0}=M0|T], Depth) when C0 =:= $p;
+						     C0 =:= $w ->
+    C = C0 - ($a - $A),				%To uppercase.
+    #{args:=Args} = M0,
+    M = M0#{control_char:=C,args:=Args++[Depth]},
+    [M|limit_format(T, Depth)];
+limit_format([H|T], Depth) ->
+    [H|limit_format(T, Depth)];
+limit_format([], _) ->
+    [].
+
 parse_event({error, _GL, {Pid, Format, Args}}) ->
     {"ERROR REPORT",Pid,[{Format,Args}]};
 parse_event({info_msg, _GL, {Pid, Format, Args}}) ->
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