From ab6c51ac00509a31d452dc3ac63d914895fac4aa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Fri, 28 Aug 2015 10:00:54 +0200 Subject: zip_SUITE: Don't trust priv_dir to be empty The unzip_to_binary/1 and zip_to_binary/1 test cases need the test_server's priv_dir to be empty. On Windows, file system pecularities can prevent us from emptying priv_dir. Since the point of this test case is not to test file operations on Windows, simplify things by working in a newly created sub directory of priv_dir. --- lib/stdlib/test/zip_SUITE.erl | 20 +++++++++----------- 1 file changed, 9 insertions(+), 11 deletions(-) (limited to 'lib/stdlib') diff --git a/lib/stdlib/test/zip_SUITE.erl b/lib/stdlib/test/zip_SUITE.erl index 9d48d092cf..c275053691 100644 --- a/lib/stdlib/test/zip_SUITE.erl +++ b/lib/stdlib/test/zip_SUITE.erl @@ -556,9 +556,10 @@ unzip_to_binary(doc) -> unzip_to_binary(Config) when is_list(Config) -> DataDir = ?config(data_dir, Config), PrivDir = ?config(priv_dir, Config), + WorkDir = filename:join(PrivDir, "unzip_to_binary"), + _ = file:make_dir(WorkDir), - delete_all_in(PrivDir), - file:set_cwd(PrivDir), + ok = file:set_cwd(WorkDir), Long = filename:join(DataDir, "abc.zip"), %% Unzip a zip file into a binary @@ -569,7 +570,7 @@ unzip_to_binary(Config) when is_list(Config) -> end, FBList), %% Make sure no files created in cwd - {ok,[]} = file:list_dir(PrivDir), + {ok,[]} = file:list_dir(WorkDir), ok. @@ -578,8 +579,10 @@ zip_to_binary(doc) -> zip_to_binary(Config) when is_list(Config) -> DataDir = ?config(data_dir, Config), PrivDir = ?config(priv_dir, Config), - delete_all_in(PrivDir), - file:set_cwd(PrivDir), + WorkDir = filename:join(PrivDir, "zip_to_binary"), + _ = file:make_dir(WorkDir), + + file:set_cwd(WorkDir), FileName = "abc.txt", ZipName = "t.zip", FilePath = filename:join(DataDir, FileName), @@ -589,7 +592,7 @@ zip_to_binary(Config) when is_list(Config) -> {ok, {ZipName, ZipB}} = zip:zip(ZipName, [FileName], [memory]), %% Make sure no files created in cwd - {ok,[FileName]} = file:list_dir(PrivDir), + {ok,[FileName]} = file:list_dir(WorkDir), %% Zip to a file {ok, ZipName} = zip:zip(ZipName, [FileName]), @@ -696,11 +699,6 @@ do_delete_files([Item|Rest], Cnt) -> end, do_delete_files(Rest, Cnt + DelCnt). -delete_all_in(Dir) -> - {ok, Files} = file:list_dir(Dir), - delete_files(lists:map(fun(F) -> filename:join(Dir,F) end, - Files)). - compress_control(doc) -> ["Test control of which files that should be compressed"]; compress_control(suite) -> []; -- cgit v1.2.3 From 1afcce230bc62c04bc6ff7b105bf33be770fea29 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Fri, 28 Aug 2015 12:52:03 +0200 Subject: proc_lib_SUITE: Remove added report handlers Report handlers are not automatically removed. That means that the report handler will remain installed until the entire running of the stdlib test suite finishes. That could potentially cause problems. --- lib/stdlib/test/proc_lib_SUITE.erl | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) (limited to 'lib/stdlib') diff --git a/lib/stdlib/test/proc_lib_SUITE.erl b/lib/stdlib/test/proc_lib_SUITE.erl index 36f009eec6..437c981461 100644 --- a/lib/stdlib/test/proc_lib_SUITE.erl +++ b/lib/stdlib/test/proc_lib_SUITE.erl @@ -149,7 +149,11 @@ crash(Config) when is_list(Config) -> ?line ?t:fail({unexpected_message,Any}) after 2000 -> ok - end. + end, + + error_logger:delete_report_handler(?MODULE), + ok. + sync_start_nolink(Config) when is_list(Config) -> @@ -301,6 +305,7 @@ hibernate(Config) when is_list(Config) -> ?line {value,{initial_call,{?MODULE,hib_loop,[_]}}} = lists:keysearch(initial_call, 1, Report), + error_logger:delete_report_handler(?MODULE), ok. hib_loop(LoopData) -> -- cgit v1.2.3 From 7e5c215b3ee06f4f425f45b4c28fe66b3c987bca Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Tue, 18 Aug 2015 15:27:00 +0200 Subject: Add error_logger_h_SUITE --- lib/stdlib/test/Makefile | 1 + lib/stdlib/test/error_logger_h_SUITE.erl | 324 +++++++++++++++++++++++++++++++ 2 files changed, 325 insertions(+) create mode 100644 lib/stdlib/test/error_logger_h_SUITE.erl (limited to 'lib/stdlib') diff --git a/lib/stdlib/test/Makefile b/lib/stdlib/test/Makefile index d4ab674486..e366c2b755 100644 --- a/lib/stdlib/test/Makefile +++ b/lib/stdlib/test/Makefile @@ -30,6 +30,7 @@ MODULES= \ erl_lint_SUITE \ erl_pp_SUITE \ erl_scan_SUITE \ + error_logger_h_SUITE \ escript_SUITE \ ets_SUITE \ ets_tough_SUITE \ diff --git a/lib/stdlib/test/error_logger_h_SUITE.erl b/lib/stdlib/test/error_logger_h_SUITE.erl new file mode 100644 index 0000000000..cd0d3a511e --- /dev/null +++ b/lib/stdlib/test/error_logger_h_SUITE.erl @@ -0,0 +1,324 @@ +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 2015. 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. +%% You may obtain a copy of the License at +%% +%% http://www.apache.org/licenses/LICENSE-2.0 +%% +%% Unless required by applicable law or agreed to in writing, software +%% distributed under the License is distributed on an "AS IS" BASIS, +%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +%% See the License for the specific language governing permissions and +%% limitations under the License. +%% +%% %CopyrightEnd% +%% +-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]). + +%% Event handler exports. +-export([init/1,handle_event/2,terminate/2]). + +-include_lib("test_server/include/test_server.hrl"). + +suite() -> [{ct_hooks,[ts_install_cth]}]. + +all() -> + [logfile,tty]. + +groups() -> + []. + +init_per_suite(Config) -> + Config. + +end_per_suite(_Config) -> + ok. + +init_per_group(_GroupName, Config) -> + Config. + +end_per_group(_GroupName, Config) -> + Config. + +logfile(Config) -> + PrivDir = ?config(priv_dir, Config), + LogDir = filename:join(PrivDir, ?MODULE), + Log = filename:join(LogDir, "logfile.log"), + ok = filelib:ensure_dir(Log), + + Ev = event_templates(), + + error_logger:logfile({open,Log}), + gen_events(Ev), + error_logger:logfile(close), + analyse_events(Log, Ev, []), + + Pa = "-pa " ++ filename:dirname(code:which(?MODULE)), + {ok,Node} = start_node(logfile, Pa), + error_logger:logfile({open,Log}), + 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]), + + test_server:stop_node(Node), + + cleanup(Log), + ok. + +tty(Config) -> + PrivDir = ?config(priv_dir, Config), + LogDir = filename:join(PrivDir, ?MODULE), + Log = filename:join(LogDir, "tty.log"), + ok = filelib:ensure_dir(Log), + + Ev = event_templates(), + + tty_log_open(Log), + gen_events(Ev), + tty_log_close(), + analyse_events(Log, Ev, []), + + Pa = "-pa " ++ filename:dirname(code:which(?MODULE)), + {ok,Node} = start_node(logfile, Pa), + tty_log_open(Log), + 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]), + + test_server:stop_node(Node), + + cleanup(Log), + ok. + +tty_log_open(Log) -> + {ok,Fd} = file:open(Log, [write]), + error_logger:add_report_handler(?MODULE, Fd), + Fd. + +tty_log_close() -> + error_logger:delete_report_handler(?MODULE), + ok. + +event_templates() -> + [{error_msg,["Pure error string\n",[]]}, + {error_msg,["Pure error string with error ~p\n",[]]}, + {error_msg,["Error string with ~p\n", [format]]}, + {error_msg,["Error string with bad format ~p\n", []]}, + + {error_report,[error_atom]}, + {error_report,["error string"]}, + {error_report,[[{error_tag,value},error_value]]}, + + {info_msg,["Pure info string\n",[]]}, + {info_msg,["Pure info string with error ~p\n",[]]}, + {info_msg,["Pure string with ~p\n", [format]]}, + {info_msg,["Pure string with bad format ~p\n", []]}, + + {info_report,[info_atom]}, + {info_report,["info string"]}, + {info_report,[[{info_tag,value},info_value]]}, + + {warning_msg,["Pure warning string\n",[]]}, + {warning_msg,["Pure warning string with error ~p\n",[]]}, + {warning_msg,["Warning string with ~p\n", [format]]}, + {warning_msg,["Warning string with bad format ~p\n", []]}, + + {warning_report,[warning_atom]}, + {warning_report,["warning string"]}, + {warning_report,[[{warning_tag,value},warning_value]]}]. + +gen_events(Ev) -> + io:format("node = ~p\n", [node()]), + io:format("group leader = ~p\n", [group_leader()]), + io:format("~p\n", [gen_event:which_handlers(error_logger)]), + call_error_logger(Ev), + + {Pid,Ref} = spawn_monitor(fun() -> error(ouch) end), + receive + {'DOWN',Ref,process,Pid,_} -> + ok + end, + + %% The following calls with a custom type will be ignored. + error_logger:error_report(ignored, value), + error_logger:warning_report(ignored, value), + error_logger:info_report(ignored, value), + receive after 100 -> ok end, + ok. + +analyse_events(Log, Ev, AtNode) -> + {ok,Bin} = file:read_file(Log), + + io:format("*** Contents of log file ***\n\n~s\n", [Bin]), + + Lines = binary:split(Bin, <<"\n">>, [global,trim_all]), + io:format("~p\n", [Lines]), + + Rest = match_output(Ev, Lines, AtNode), + io:format("~p\n", [Rest]), + + [] = match_emulator_error(Rest), + ok. + + +call_error_logger([{F,Args}|T]) -> + apply(error_logger, F, Args), + call_error_logger(T); +call_error_logger([]) -> ok. + + +match_emulator_error([Head,Second,Third,_|Lines]) -> + match_head(<<"ERROR">>, Head), + {match,[{0,_}]} = re:run(Second, + "^Error in process <\\d+[.]\\d+[.]\\d+> on " + "node [^ ]* with exit value:"), + {match,[{0,_}]} = re:run(Third, "^[{]ouch,"), + Lines. + +match_output([Item|T], Lines0, AtNode) -> + try match_item(Item, Lines0, AtNode) of + Lines -> + match_output(T, Lines, AtNode) + catch + C:E -> + Stk = erlang:get_stacktrace(), + io:format("ITEM: ~p", [Item]), + io:format("LINES: ~p", [Lines0]), + erlang:raise(C, E, Stk) + end; +match_output([], Lines, _) -> Lines. + +match_item(Item, Lines, AtNode) -> + case item_type(Item) of + {msg,Head,Args} -> + match_format(Head, Args, Lines, AtNode); + {report,Head,Args} -> + match_term(Head, Args, Lines, AtNode) + end. + +item_type({error_msg,Args}) -> + {msg,<<"ERROR">>,Args}; +item_type({info_msg,Args}) -> + {msg,<<"INFO">>,Args}; +item_type({warning_msg,Args}) -> + {msg,<<"WARNING">>,Args}; +item_type({error_report,Args}) -> + {report,<<"ERROR">>,Args}; +item_type({info_report,Args}) -> + {report,<<"INFO">>,Args}; +item_type({warning_report,Args}) -> + {report,<<"WARNING">>,Args}. + +match_format(Tag, [Format,Args], [Head|Lines], AtNode) -> + match_head(Tag, Head), + Bin = try io_lib:format(Format, Args) of + Str -> + iolist_to_binary(Str) + catch + _:_ -> + S = io_lib:format("ERROR: ~p - ~p~n", [Format,Args]), + iolist_to_binary(S) + end, + Expected0 = binary:split(Bin, <<"\n">>, [trim_all]), + Expected = Expected0 ++ AtNode, + match_term_lines(Expected, Lines). + +match_term(Tag, [Arg], [Head|Lines], AtNode) -> + match_head(Tag, Head), + Expected0 = match_term_get_expected(Arg), + 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]), + Bin = iolist_to_binary(S), + [Bin]. + +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([]) -> []. + +match_term_lines([Line|T], [Line|Lines]) -> + match_term_lines(T, Lines); +match_term_lines([], Lines) -> Lines. + +match_head(Tag, Head) -> + Re = <<"^=",Tag/binary, + " REPORT==== \\d\\d?-[A-Z][a-z][a-z]-\\d{4}::" + "\\d\\d:\\d\\d:\\d\\d ===$">>, + {match,_} = re:run(Head, Re). + +start_node(Name, Args) -> + case test_server:start_node(Name, slave, [{args,Args}]) of + {ok,Node} -> + {ok,Node}; + Error -> + test_server:fail(Error) + end. + +cleanup(File) -> + %% The point of this test case is not to test file operations. + %% Therefore ignore any failures. + case file:delete(File) of + ok -> + ok; + {error,Error1} -> + io:format("file:delete(~s) failed with error ~p", + [File,Error1]) + end, + Dir = filename:dirname(File), + case file:del_dir(Dir) of + ok -> + ok; + {error,Error2} -> + io:format("file:del_dir(~s) failed with error ~p", + [Dir,Error2]) + end, + ok. + + +%%% +%%% 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 +%%% calling error_logger_tty_h:write_event/2. +%%% + +init(Fd) -> + {ok,Fd}. + +handle_event(Event, Fd) -> + case error_logger_tty_h:write_event(tag_event(Event), io_lib) of + ok -> + ok; + Str when is_list(Str) -> + io:put_chars(Fd, Str) + end, + {ok,Fd}. + +terminate(_Reason, Fd) -> + ok = file:close(Fd), + []. + +tag_event(Event) -> + {erlang:universaltime(),Event}. -- cgit v1.2.3 From 7dbd3caa955ad9da7c1da97cee9d53a311b26908 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Thu, 20 Aug 2015 09:44:43 +0200 Subject: Remove unused code in error logger handlers A long time ago, errors from the emulator itself was sent as messages that would end up in the handle_info/2 function. Those clauses in handle_info/2 can be removed. The code for handling events tagged 'info' instead of 'info_msg' can also be taken out. --- lib/stdlib/src/error_logger_file_h.erl | 24 ++---------------------- lib/stdlib/src/error_logger_tty_h.erl | 23 ++--------------------- 2 files changed, 4 insertions(+), 43 deletions(-) (limited to 'lib/stdlib') diff --git a/lib/stdlib/src/error_logger_file_h.erl b/lib/stdlib/src/error_logger_file_h.erl index a7f3615972..bf74ad28bb 100644 --- a/lib/stdlib/src/error_logger_file_h.erl +++ b/lib/stdlib/src/error_logger_file_h.erl @@ -24,12 +24,10 @@ %%% %%% A handler that can be connected to the error_logger -%%% event handler. -%%% Writes all events formatted to file. -%%% Handles events tagged error, emulator and info. +%%% event handler. Writes all events formatted to file. %%% %%% It can only be started from error_logger:swap_handler({logfile, File}) -%%% or error_logger:logfile(File) +%%% or error_logger:logfile(File). %%% -export([init/1, @@ -73,13 +71,6 @@ handle_info({'EXIT', Fd, _Reason}, {Fd, _File, PrevHandler}) -> _ -> {swap_handler, install_prev, [], PrevHandler, go_back} end; -handle_info({emulator, GL, Chars}, {Fd, File, PrevHandler}) - when node(GL) == node() -> - write_event(Fd, tag_event({emulator, GL, Chars})), - {ok, {Fd, File, PrevHandler}}; -handle_info({emulator, noproc, Chars}, {Fd, File, PrevHandler}) -> - write_event(Fd, tag_event({emulator, noproc, Chars})), - {ok, {Fd, File, PrevHandler}}; handle_info(_, State) -> {ok, State}. @@ -124,17 +115,6 @@ write_event(Fd, {Time, {error, _GL, {Pid, Format, Args}}}) -> F = add_node("ERROR: ~p - ~p~n", Pid), io:format(Fd, T ++ F, [Format,Args]) end; -write_event(Fd, {Time, {emulator, _GL, Chars}}) -> - T = write_time(maybe_utc(Time)), - case catch io_lib:format(Chars, []) of - S when is_list(S) -> - io:format(Fd, T ++ S, []); - _ -> - io:format(Fd, T ++ "ERROR: ~p ~n", [Chars]) - end; -write_event(Fd, {Time, {info, _GL, {Pid, Info, _}}}) -> - T = write_time(maybe_utc(Time)), - io:format(Fd, T ++ add_node("~p~n",Pid),[Info]); write_event(Fd, {Time, {error_report, _GL, {Pid, std_error, Rep}}}) -> T = write_time(maybe_utc(Time)), S = format_report(Rep), diff --git a/lib/stdlib/src/error_logger_tty_h.erl b/lib/stdlib/src/error_logger_tty_h.erl index 65ea645bd9..5307dac6d0 100644 --- a/lib/stdlib/src/error_logger_tty_h.erl +++ b/lib/stdlib/src/error_logger_tty_h.erl @@ -23,12 +23,10 @@ %%% %%% A handler that can be connected to the error_logger -%%% event handler. -%%% Writes all events formatted to stdout. -%%% Handles events tagged error, emulator and info. +%%% event handler. Writes all events formatted to stdout. %%% %%% It can only be started from error_logger:swap_handler(tty) -%%% or error_logger:tty(true) +%%% or error_logger:tty(true). %%% -export([init/1, @@ -66,12 +64,6 @@ handle_info({'EXIT', User, _Reason}, {User, PrevHandler}) -> {swap_handler, install_prev, {User, PrevHandler}, PrevHandler, go_back} end; -handle_info({emulator, GL, Chars}, State) when node(GL) == node() -> - ok = write_event(tag_event({emulator, GL, Chars}),io), - {ok, State}; -handle_info({emulator, noproc, Chars}, State) -> - ok = write_event(tag_event({emulator, noproc, Chars}),io), - {ok, State}; handle_info(_, State) -> {ok, State}. @@ -118,17 +110,6 @@ write_event({Time, {error, _GL, {Pid, Format, Args}}},IOMod) -> F = add_node("ERROR: ~p - ~p~n", Pid), format(IOMod, T ++ F, [Format,Args]) end; -write_event({Time, {emulator, _GL, Chars}},IOMod) -> - T = write_time(maybe_utc(Time)), - case catch io_lib:format(Chars, []) of - S when is_list(S) -> - format(IOMod, T ++ S); - _ -> - format(IOMod, T ++ "ERROR: ~p ~n", [Chars]) - end; -write_event({Time, {info, _GL, {Pid, Info, _}}},IOMod) -> - T = write_time(maybe_utc(Time)), - format(IOMod, T ++ add_node("~p~n",Pid),[Info]); write_event({Time, {error_report, _GL, {Pid, std_error, Rep}}},IOMod) -> T = write_time(maybe_utc(Time)), S = format_report(Rep), -- cgit v1.2.3 From 003091a1fcc749a182505ef5675c763f71eacbb0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Thu, 20 Aug 2015 12:29:29 +0200 Subject: error_logger_file_h: Refactor and modernize code Refactor, simplify, and modernize the code to facilitate future improvements in the following commits. --- lib/stdlib/src/error_logger_file_h.erl | 164 ++++++++++++++++----------------- 1 file changed, 78 insertions(+), 86 deletions(-) (limited to 'lib/stdlib') diff --git a/lib/stdlib/src/error_logger_file_h.erl b/lib/stdlib/src/error_logger_file_h.erl index bf74ad28bb..5f8bf9092a 100644 --- a/lib/stdlib/src/error_logger_file_h.erl +++ b/lib/stdlib/src/error_logger_file_h.erl @@ -34,12 +34,17 @@ handle_event/2, handle_call/2, handle_info/2, terminate/2, code_change/3]). +-record(st, + {fd, + filename, + prev_handler}). + %% This one is used when we takeover from the simple error_logger. init({File, {error_logger, Buf}}) -> case init(File, error_logger) of - {ok, {Fd, File, PrevHandler}} -> - write_events(Fd, Buf), - {ok, {Fd, File, PrevHandler}}; + {ok, State} -> + write_events(State, Buf), + {ok, State}; Error -> Error end; @@ -51,20 +56,18 @@ init(File, PrevHandler) -> process_flag(trap_exit, true), case file:open(File, [write]) of {ok,Fd} -> - {ok, {Fd, File, PrevHandler}}; + {ok, #st{fd=Fd,filename=File,prev_handler=PrevHandler}}; Error -> Error end. handle_event({_Type, GL, _Msg}, State) when node(GL) =/= node() -> {ok, State}; -handle_event(Event, {Fd, File, PrevHandler}) -> - write_event(Fd, tag_event(Event)), - {ok, {Fd, File, PrevHandler}}; -handle_event(_, State) -> +handle_event(Event, State) -> + write_event(State, Event), {ok, State}. -handle_info({'EXIT', Fd, _Reason}, {Fd, _File, PrevHandler}) -> +handle_info({'EXIT', Fd, _Reason}, #st{fd=Fd,prev_handler=PrevHandler}) -> case PrevHandler of [] -> remove_handler; @@ -74,8 +77,8 @@ handle_info({'EXIT', Fd, _Reason}, {Fd, _File, PrevHandler}) -> handle_info(_, State) -> {ok, State}. -handle_call(filename, {Fd, File, Prev}) -> - {ok, File, {Fd, File, Prev}}; +handle_call(filename, #st{filename=File}=State) -> + {ok, File, State}; handle_call(_Query, State) -> {ok, {error, bad_query}, State}. @@ -95,58 +98,55 @@ code_change(_OldVsn, State, _Extra) -> %%% Misc. functions. %%% ------------------------------------------------------ -tag_event(Event) -> - {erlang:universaltime(), Event}. +write_events(State, [Ev|Es]) -> + %% Write the events in reversed order. + write_events(State, Es), + write_event(State, Ev); +write_events(_State, []) -> + ok. -write_events(Fd, Events) -> write_events1(Fd, lists:reverse(Events)). +write_event(#st{fd=Fd}=State, Event) -> + case parse_event(Event) of + ignore -> + ok; + {Head,Pid,FormatList} -> + Time = maybe_utc(erlang:universaltime()), + Header = write_time(Time, Head), + Body = format_body(State, FormatList), + AtNode = if + node(Pid) =/= node() -> + ["** at node ",atom_to_list(node(Pid))," **\n"]; + true -> + [] + end, + io:put_chars(Fd, [Header,Body,AtNode]) + end. -write_events1(Fd, [Event|Es]) -> - write_event(Fd, Event), - write_events1(Fd, Es); -write_events1(_, []) -> - ok. +format_body(State, [{Format,Args}|T]) -> + S = try io_lib:format(Format, Args) of + S0 -> + S0 + catch + _:_ -> + io_lib:format("ERROR: ~p - ~p\n", [Format,Args]) + end, + [S|format_body(State, T)]; +format_body(_State, []) -> + []. -write_event(Fd, {Time, {error, _GL, {Pid, Format, Args}}}) -> - T = write_time(maybe_utc(Time)), - case catch io_lib:format(add_node(Format,Pid), Args) of - S when is_list(S) -> - io:format(Fd, T ++ S, []); - _ -> - F = add_node("ERROR: ~p - ~p~n", Pid), - io:format(Fd, T ++ F, [Format,Args]) - end; -write_event(Fd, {Time, {error_report, _GL, {Pid, std_error, Rep}}}) -> - T = write_time(maybe_utc(Time)), - S = format_report(Rep), - io:format(Fd, T ++ S ++ add_node("", Pid), []); -write_event(Fd, {Time, {info_report, _GL, {Pid, std_info, Rep}}}) -> - T = write_time(maybe_utc(Time), "INFO REPORT"), - S = format_report(Rep), - io:format(Fd, T ++ S ++ add_node("", Pid), []); -write_event(Fd, {Time, {info_msg, _GL, {Pid, Format, Args}}}) -> - T = write_time(maybe_utc(Time), "INFO REPORT"), - case catch io_lib:format(add_node(Format,Pid), Args) of - S when is_list(S) -> - io:format(Fd, T ++ S, []); - _ -> - F = add_node("ERROR: ~p - ~p~n", Pid), - io:format(Fd, T ++ F, [Format,Args]) - end; -write_event(Fd, {Time, {warning_report, _GL, {Pid, std_warning, Rep}}}) -> - T = write_time(maybe_utc(Time), "WARNING REPORT"), - S = format_report(Rep), - io:format(Fd, T ++ S ++ add_node("", Pid), []); -write_event(Fd, {Time, {warning_msg, _GL, {Pid, Format, Args}}}) -> - T = write_time(maybe_utc(Time), "WARNING REPORT"), - case catch io_lib:format(add_node(Format,Pid), Args) of - S when is_list(S) -> - io:format(Fd, T ++ S, []); - _ -> - F = add_node("ERROR: ~p - ~p~n", Pid), - io:format(Fd, T ++ F, [Format,Args]) - end; -write_event(_, _) -> - ok. +parse_event({error, _GL, {Pid, Format, Args}}) -> + {"ERROR REPORT",Pid,[{Format,Args}]}; +parse_event({info_msg, _GL, {Pid, Format, Args}}) -> + {"INFO REPORT",Pid,[{Format, Args}]}; +parse_event({warning_msg, _GL, {Pid, Format, Args}}) -> + {"WARNING REPORT",Pid,[{Format,Args}]}; +parse_event({error_report, _GL, {Pid, std_error, Args}}) -> + {"ERROR REPORT",Pid,format_term(Args)}; +parse_event({info_report, _GL, {Pid, std_info, Args}}) -> + {"INFO REPORT",Pid,format_term(Args)}; +parse_event({warning_report, _GL, {Pid, std_warning, Args}}) -> + {"WARNING REPORT",Pid,format_term(Args)}; +parse_event(_) -> ignore. maybe_utc(Time) -> UTC = case application:get_env(sasl, utc_log) of @@ -163,30 +163,27 @@ maybe_utc(Time) -> maybe_utc(Time, true) -> {utc, Time}; maybe_utc(Time, _) -> {local, calendar:universal_time_to_local_time(Time)}. -format_report(Rep) when is_list(Rep) -> - case string_p(Rep) of +format_term(Term) when is_list(Term) -> + case string_p(Term) of true -> - io_lib:format("~s~n",[Rep]); - _ -> - format_rep(Rep) + [{"~s\n",[Term]}]; + false -> + format_term_list(Term) end; -format_report(Rep) -> - io_lib:format("~p~n",[Rep]). - -format_rep([{Tag,Data}|Rep]) -> - io_lib:format(" ~p: ~p~n",[Tag,Data]) ++ format_rep(Rep); -format_rep([Other|Rep]) -> - io_lib:format(" ~p~n",[Other]) ++ format_rep(Rep); -format_rep(_) -> +format_term(Term) -> + [{"~p\n",[Term]}]. + +format_term_list([{Tag,Data}|T]) -> + [{" ~p: ~p\n",[Tag,Data]}|format_term_list(T)]; +format_term_list([Data|T]) -> + [{" ~p\n",[Data]}|format_term_list(T)]; +format_term_list([]) -> + []; +format_term_list(_) -> + %% Continue to allow non-proper lists for now. + %% FIXME: Remove this clause in OTP 19. []. -add_node(X, Pid) when is_atom(X) -> - add_node(atom_to_list(X), Pid); -add_node(X, Pid) when node(Pid) =/= node() -> - lists:concat([X,"** at node ",node(Pid)," **~n"]); -add_node(X, _) -> - X. - string_p([]) -> false; string_p(Term) -> @@ -202,15 +199,10 @@ string_p1([$\b|T]) -> string_p1(T); string_p1([$\f|T]) -> string_p1(T); string_p1([$\e|T]) -> string_p1(T); string_p1([H|T]) when is_list(H) -> - case string_p1(H) of - true -> string_p1(T); - _ -> false - end; + string_p1(H) andalso string_p1(T); string_p1([]) -> true; string_p1(_) -> false. -write_time(Time) -> write_time(Time, "ERROR REPORT"). - write_time({utc,{{Y,Mo,D},{H,Mi,S}}}, Type) -> io_lib:format("~n=~s==== ~p-~s-~p::~s:~s:~s UTC ===~n", [Type,D,month(Mo),Y,t(H),t(Mi),t(S)]); -- cgit v1.2.3 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/src/error_logger_file_h.erl | 40 +++++++-- lib/stdlib/test/error_logger_h_SUITE.erl | 145 +++++++++++++++++++++---------- 2 files changed, 134 insertions(+), 51 deletions(-) (limited to 'lib/stdlib') 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 -- cgit v1.2.3 From 62a8c96e22951d6b8d696b32d898c823969f4812 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Thu, 20 Aug 2015 12:29:29 +0200 Subject: error_logger_tty_h: Refactor and modernize code Refactor, simplify, and modernize the code to facilitate future improvements in the following commits. --- lib/stdlib/src/error_logger_tty_h.erl | 180 ++++++++++++++++++---------------- 1 file changed, 97 insertions(+), 83 deletions(-) (limited to 'lib/stdlib') diff --git a/lib/stdlib/src/error_logger_tty_h.erl b/lib/stdlib/src/error_logger_tty_h.erl index 5307dac6d0..5dd8b0caa0 100644 --- a/lib/stdlib/src/error_logger_tty_h.erl +++ b/lib/stdlib/src/error_logger_tty_h.erl @@ -35,33 +35,40 @@ -export([write_event/2]). +-record(st, + {user, + prev_handler, + io_mod=io}). + %% This one is used when we takeover from the simple error_logger. init({[], {error_logger, Buf}}) -> User = set_group_leader(), - write_events(Buf,io), - {ok, {User, error_logger}}; + State = #st{user=User,prev_handler=error_logger}, + write_events(State, Buf), + {ok, State}; %% This one is used if someone took over from us, and now wants to %% go back. init({[], {error_logger_tty_h, PrevHandler}}) -> User = set_group_leader(), - {ok, {User, PrevHandler}}; + {ok, #st{user=User,prev_handler=PrevHandler}}; %% This one is used when we are started directly. init([]) -> User = set_group_leader(), - {ok, {User, []}}. + {ok, #st{user=User,prev_handler=[]}}. handle_event({_Type, GL, _Msg}, State) when node(GL) =/= node() -> {ok, State}; handle_event(Event, State) -> - ok = write_event(tag_event(Event),io), + ok = do_write_event(State, tag_event(Event)), {ok, State}. -handle_info({'EXIT', User, _Reason}, {User, PrevHandler}) -> +handle_info({'EXIT', User, _Reason}, + #st{user=User,prev_handler=PrevHandler}=State) -> case PrevHandler of [] -> remove_handler; _ -> - {swap_handler, install_prev, {User, PrevHandler}, + {swap_handler, install_prev, State, PrevHandler, go_back} end; handle_info(_, State) -> @@ -69,80 +76,95 @@ handle_info(_, State) -> handle_call(_Query, State) -> {ok, {error, bad_query}, State}. -% unfortunately, we can't unlink from User - links are not counted! -% if pid(User) -> unlink(User); true -> ok end, terminate(install_prev, _State) -> []; -terminate(_Reason, {_User, PrevHandler}) -> +terminate(_Reason, #st{prev_handler=PrevHandler}) -> {error_logger_tty_h, PrevHandler}. code_change(_OldVsn, State, _Extra) -> {ok, State}. +%% Exported (but unoffical) API. +write_event(Event, IoMod) -> + do_write_event(#st{io_mod=IoMod}, Event). + + %%% ------------------------------------------------------ %%% Misc. functions. %%% ------------------------------------------------------ set_group_leader() -> case whereis(user) of - User when is_pid(User) -> link(User), group_leader(User,self()), User; - _ -> false + User when is_pid(User) -> + link(User), + group_leader(User,self()), + User; + _ -> + false end. tag_event(Event) -> {erlang:universaltime(), Event}. -%% IOMOd is always 'io' -write_events(Events,IOMod) -> write_events1(lists:reverse(Events),IOMod). - -write_events1([Event|Es],IOMod) -> - ok = write_event(Event,IOMod), - write_events1(Es,IOMod); -write_events1([],_IOMod) -> +write_events(State, [Ev|Es]) -> + %% Write the events in reverse order. + _ = write_events(State, Es), + _ = do_write_event(State, Ev), + ok; +write_events(_State, []) -> ok. -write_event({Time, {error, _GL, {Pid, Format, Args}}},IOMod) -> - T = write_time(maybe_utc(Time)), - case catch io_lib:format(add_node(Format,Pid), Args) of - S when is_list(S) -> - format(IOMod, T ++ S); - _ -> - F = add_node("ERROR: ~p - ~p~n", Pid), - format(IOMod, T ++ F, [Format,Args]) +do_write_event(State, {Time0, Event}) -> + case parse_event(Event) of + ignore -> + ok; + {Head,Pid,FormatList} -> + Time = maybe_utc(Time0), + Header = write_time(Time, Head), + Body = format_body(State, FormatList), + AtNode = if + node(Pid) =/= node() -> + ["** at node ",atom_to_list(node(Pid))," **\n"]; + true -> + [] + end, + Str = [Header,Body,AtNode], + case State#st.io_mod of + io_lib -> + Str; + io -> + io:put_chars(user, Str) + end end; -write_event({Time, {error_report, _GL, {Pid, std_error, Rep}}},IOMod) -> - T = write_time(maybe_utc(Time)), - S = format_report(Rep), - format(IOMod, T ++ S ++ add_node("", Pid)); -write_event({Time, {info_report, _GL, {Pid, std_info, Rep}}},IOMod) -> - T = write_time(maybe_utc(Time), "INFO REPORT"), - S = format_report(Rep), - format(IOMod, T ++ S ++ add_node("", Pid)); -write_event({Time, {info_msg, _GL, {Pid, Format, Args}}},IOMod) -> - T = write_time(maybe_utc(Time), "INFO REPORT"), - case catch io_lib:format(add_node(Format,Pid), Args) of - S when is_list(S) -> - format(IOMod, T ++ S); - _ -> - F = add_node("ERROR: ~p - ~p~n", Pid), - format(IOMod, T ++ F, [Format,Args]) - end; -write_event({Time, {warning_report, _GL, {Pid, std_warning, Rep}}},IOMod) -> - T = write_time(maybe_utc(Time), "WARNING REPORT"), - S = format_report(Rep), - format(IOMod, T ++ S ++ add_node("", Pid)); -write_event({Time, {warning_msg, _GL, {Pid, Format, Args}}},IOMod) -> - T = write_time(maybe_utc(Time), "WARNING REPORT"), - case catch io_lib:format(add_node(Format,Pid), Args) of - S when is_list(S) -> - format(IOMod, T ++ S); - _ -> - F = add_node("ERROR: ~p - ~p~n", Pid), - format(IOMod, T ++ F, [Format,Args]) - end; -write_event({_Time, _Error},_IOMod) -> +do_write_event(_, _) -> ok. +format_body(State, [{Format,Args}|T]) -> + S = try io_lib:format(Format, Args) of + S0 -> + S0 + catch + _:_ -> + io_lib:format("ERROR: ~p - ~p\n", [Format,Args]) + end, + [S|format_body(State, T)]; +format_body(_State, []) -> + []. + +parse_event({error, _GL, {Pid, Format, Args}}) -> + {"ERROR REPORT",Pid,[{Format,Args}]}; +parse_event({info_msg, _GL, {Pid, Format, Args}}) -> + {"INFO REPORT",Pid,[{Format, Args}]}; +parse_event({warning_msg, _GL, {Pid, Format, Args}}) -> + {"WARNING REPORT",Pid,[{Format,Args}]}; +parse_event({error_report, _GL, {Pid, std_error, Args}}) -> + {"ERROR REPORT",Pid,format_term(Args)}; +parse_event({info_report, _GL, {Pid, std_info, Args}}) -> + {"INFO REPORT",Pid,format_term(Args)}; +parse_event({warning_report, _GL, {Pid, std_warning, Args}}) -> + {"WARNING REPORT",Pid,format_term(Args)}; +parse_event(_) -> ignore. + maybe_utc(Time) -> UTC = case application:get_env(sasl, utc_log) of {ok, Val} -> Val; @@ -158,33 +180,26 @@ maybe_utc(Time) -> maybe_utc(Time, true) -> {utc, Time}; maybe_utc(Time, _) -> {local, calendar:universal_time_to_local_time(Time)}. -format(IOMod, String) -> format(IOMod, String, []). -format(io_lib, String, Args) -> io_lib:format(String, Args); -format(io, String, Args) -> io:format(user, String, Args). - -format_report(Rep) when is_list(Rep) -> - case string_p(Rep) of +format_term(Term) when is_list(Term) -> + case string_p(Term) of true -> - io_lib:format("~s~n",[Rep]); - _ -> - format_rep(Rep) + [{"~s\n",[Term]}]; + false -> + format_term_list(Term) end; -format_report(Rep) -> - io_lib:format("~p~n",[Rep]). - -format_rep([{Tag,Data}|Rep]) -> - io_lib:format(" ~p: ~p~n",[Tag,Data]) ++ format_rep(Rep); -format_rep([Other|Rep]) -> - io_lib:format(" ~p~n",[Other]) ++ format_rep(Rep); -format_rep(_) -> - []. +format_term(Term) -> + [{"~p\n",[Term]}]. -add_node(X, Pid) when is_atom(X) -> - add_node(atom_to_list(X), Pid); -add_node(X, Pid) when node(Pid) =/= node() -> - lists:concat([X,"** at node ",node(Pid)," **~n"]); -add_node(X, _) -> - X. +format_term_list([{Tag,Data}|T]) -> + [{" ~p: ~p\n",[Tag,Data]}|format_term_list(T)]; +format_term_list([Data|T]) -> + [{" ~p\n",[Data]}|format_term_list(T)]; +format_term_list([]) -> + []; +format_term_list(_) -> + %% Continue to allow non-proper lists for now. + %% FIXME: Remove this clause in OTP 19. + []. string_p([]) -> false; @@ -208,7 +223,6 @@ string_p1([H|T]) when is_list(H) -> string_p1([]) -> true; string_p1(_) -> false. -write_time(Time) -> write_time(Time, "ERROR REPORT"). write_time({utc,{{Y,Mo,D},{H,Mi,S}}},Type) -> io_lib:format("~n=~s==== ~p-~s-~p::~s:~s:~s UTC ===~n", [Type,D,month(Mo),Y,t(H),t(Mi),t(S)]); -- cgit v1.2.3 From 3c3a5b08589a6e54b0d2d81e470fcffaaa74c15c 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_tty_h to truncate big messages Add the possibility to truncate big messages to avoid running out of memory. --- lib/stdlib/src/error_logger_tty_h.erl | 44 +++++++++++++++++++++++++++----- lib/stdlib/test/error_logger_h_SUITE.erl | 41 ++++++++++++++++++++++------- 2 files changed, 70 insertions(+), 15 deletions(-) (limited to 'lib/stdlib') diff --git a/lib/stdlib/src/error_logger_tty_h.erl b/lib/stdlib/src/error_logger_tty_h.erl index 5dd8b0caa0..d2df6681e3 100644 --- a/lib/stdlib/src/error_logger_tty_h.erl +++ b/lib/stdlib/src/error_logger_tty_h.erl @@ -33,17 +33,19 @@ handle_event/2, handle_call/2, handle_info/2, terminate/2, code_change/3]). --export([write_event/2]). +-export([write_event/2,write_event/3]). -record(st, {user, prev_handler, - io_mod=io}). + io_mod=io, + depth=unlimited}). %% This one is used when we takeover from the simple error_logger. init({[], {error_logger, Buf}}) -> User = set_group_leader(), - State = #st{user=User,prev_handler=error_logger}, + Depth = get_depth(), + State = #st{user=User,prev_handler=error_logger,depth=Depth}, write_events(State, Buf), {ok, State}; %% This one is used if someone took over from us, and now wants to @@ -54,7 +56,16 @@ init({[], {error_logger_tty_h, PrevHandler}}) -> %% This one is used when we are started directly. init([]) -> User = set_group_leader(), - {ok, #st{user=User,prev_handler=[]}}. + Depth = get_depth(), + {ok, #st{user=User,prev_handler=[],depth=Depth}}. + +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}; @@ -88,6 +99,9 @@ code_change(_OldVsn, State, _Extra) -> write_event(Event, IoMod) -> do_write_event(#st{io_mod=IoMod}, Event). +write_event(Event, IoMod, Depth) -> + do_write_event(#st{io_mod=IoMod,depth=Depth}, Event). + %%% ------------------------------------------------------ %%% Misc. functions. @@ -140,17 +154,35 @@ do_write_event(_, _) -> ok. 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 7cde659b9f..b0b9c717a1 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,logfile_truncated/1,tty/1]). +-export([logfile/1,logfile_truncated/1,tty/1,tty_truncated/1]). %% Event handler exports. -export([init/1,handle_event/2,terminate/2]). @@ -30,7 +30,7 @@ suite() -> [{ct_hooks,[ts_install_cth]}]. all() -> - [logfile,logfile_truncated,tty]. + [logfile,logfile_truncated,tty,tty_truncated]. groups() -> []. @@ -118,6 +118,25 @@ tty(Config) -> cleanup(Log), ok. +tty_truncated(Config) -> + PrivDir = ?config(priv_dir, Config), + LogDir = filename:join(PrivDir, ?MODULE), + Log = filename:join(LogDir, "tty_truncated.log"), + ok = filelib:ensure_dir(Log), + + Ev = event_templates(), + + Depth = 20, + application:set_env(kernel, error_logger_format_depth, Depth), + try + do_one_tty(Log, Ev, Depth) + after + application:unset_env(kernel, error_logger_format_depth) + end, + + cleanup(Log), + ok. + do_one_tty(Log, Ev, Depth) -> tty_log_open(Log), gen_events(Ev), @@ -126,7 +145,11 @@ do_one_tty(Log, Ev, Depth) -> tty_log_open(Log) -> {ok,Fd} = file:open(Log, [write]), - error_logger:add_report_handler(?MODULE, Fd), + Depth = case application:get_env(kernel, error_logger_format_depth) of + {ok,D} -> D; + _ -> unlimited + end, + error_logger:add_report_handler(?MODULE, {Fd,Depth}), Fd. tty_log_close() -> @@ -357,19 +380,19 @@ dl_format_1([], [], _, Facc, Aacc) -> %%% calling error_logger_tty_h:write_event/2. %%% -init(Fd) -> - {ok,Fd}. +init({_,_}=St) -> + {ok,St}. -handle_event(Event, Fd) -> - case error_logger_tty_h:write_event(tag_event(Event), io_lib) of +handle_event(Event, {Fd,Depth}=St) -> + case error_logger_tty_h:write_event(tag_event(Event), io_lib, Depth) of ok -> ok; Str when is_list(Str) -> io:put_chars(Fd, Str) end, - {ok,Fd}. + {ok,St}. -terminate(_Reason, Fd) -> +terminate(_Reason, {Fd,_}) -> ok = file:close(Fd), []. -- cgit v1.2.3 From 7df173516a08455304abd0a783c9e8b64e88859e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Tue, 25 Aug 2015 15:07:43 +0200 Subject: proc_lib: Add format/3 We'll need a way to limit the size of the crash report produced by proc_lib:format(). Add format/3, where the third argument is a depth argument. --- lib/stdlib/doc/src/proc_lib.xml | 11 +++++++ lib/stdlib/src/proc_lib.erl | 65 ++++++++++++++++++++++++-------------- lib/stdlib/test/proc_lib_SUITE.erl | 49 ++++++++++++++++++++++++++-- 3 files changed, 100 insertions(+), 25 deletions(-) (limited to 'lib/stdlib') diff --git a/lib/stdlib/doc/src/proc_lib.xml b/lib/stdlib/doc/src/proc_lib.xml index 86ade8840f..85f0c0c908 100644 --- a/lib/stdlib/doc/src/proc_lib.xml +++ b/lib/stdlib/doc/src/proc_lib.xml @@ -226,6 +226,17 @@ init(Parent) -> Pid which sent the crash report.

+ + + Format a crash report. + +

This function can be used by a user defined event handler to + format a crash report. When Depth is given as an + positive integer, it will be used in the format string to + limit the output as follows: io_lib:format("~P", + [Term,Depth]).

+ + Extract the initial call of a proc_libspawned process. diff --git a/lib/stdlib/src/proc_lib.erl b/lib/stdlib/src/proc_lib.erl index bbf4f573f5..10c476a6f5 100644 --- a/lib/stdlib/src/proc_lib.erl +++ b/lib/stdlib/src/proc_lib.erl @@ -30,7 +30,8 @@ start/3, start/4, start/5, start_link/3, start_link/4, start_link/5, hibernate/3, init_ack/1, init_ack/2, - init_p/3,init_p/5,format/1,format/2,initial_call/1, + init_p/3,init_p/5,format/1,format/2,format/3, + initial_call/1, translate_initial_call/1, stop/1, stop/3]). @@ -700,53 +701,71 @@ format(CrashReport) -> CrashReport :: [term()], Encoding :: latin1 | unicode | utf8. -format([OwnReport,LinkReport], Encoding) -> - OwnFormat = format_report(OwnReport, Encoding), - LinkFormat = format_report(LinkReport, Encoding), +format(CrashReport, Encoding) -> + format(CrashReport, Encoding, unlimited). + +-spec format(CrashReport, Encoding, Depth) -> string() when + CrashReport :: [term()], + Encoding :: latin1 | unicode | utf8, + Depth :: unlimited | pos_integer(). + +format([OwnReport,LinkReport], Encoding, Depth) -> + Extra = {Encoding,Depth}, + OwnFormat = format_report(OwnReport, Extra), + LinkFormat = format_report(LinkReport, Extra), Str = io_lib:format(" crasher:~n~ts neighbours:~n~ts", [OwnFormat, LinkFormat]), lists:flatten(Str). -format_report(Rep, Enc) when is_list(Rep) -> - format_rep(Rep,Enc); -format_report(Rep, Enc) -> +format_report(Rep, Extra) when is_list(Rep) -> + format_rep(Rep, Extra); +format_report(Rep, {Enc,_}) -> io_lib:format("~"++modifier(Enc)++"p~n", [Rep]). -format_rep([{initial_call,InitialCall}|Rep], Enc) -> - [format_mfa(InitialCall)|format_rep(Rep, Enc)]; -format_rep([{error_info,{Class,Reason,StackTrace}}|Rep], Enc) -> - [format_exception(Class, Reason, StackTrace, Enc)|format_rep(Rep, Enc)]; -format_rep([{Tag,Data}|Rep], Enc) -> - [format_tag(Tag, Data)|format_rep(Rep, Enc)]; -format_rep(_, _Enc) -> +format_rep([{initial_call,InitialCall}|Rep], {_Enc,Depth}=Extra) -> + [format_mfa(InitialCall, Depth)|format_rep(Rep, Extra)]; +format_rep([{error_info,{Class,Reason,StackTrace}}|Rep], Extra) -> + [format_exception(Class, Reason, StackTrace, Extra)|format_rep(Rep, Extra)]; +format_rep([{Tag,Data}|Rep], Extra) -> + [format_tag(Tag, Data, Extra)|format_rep(Rep, Extra)]; +format_rep(_, _Extra) -> []. -format_exception(Class, Reason, StackTrace, Enc) -> - PF = pp_fun(Enc), +format_exception(Class, Reason, StackTrace, {Enc,_}=Extra) -> + PF = pp_fun(Extra), StackFun = fun(M, _F, _A) -> (M =:= erl_eval) or (M =:= ?MODULE) end, %% EI = " exception: ", EI = " ", [EI, lib:format_exception(1+length(EI), Class, Reason, StackTrace, StackFun, PF, Enc), "\n"]. -format_mfa({M,F,Args}=StartF) -> +format_mfa({M,F,Args}=StartF, Depth) -> try A = length(Args), [" initial call: ",atom_to_list(M),$:,atom_to_list(F),$/, integer_to_list(A),"\n"] catch error:_ -> - format_tag(initial_call, StartF) + format_tag(initial_call, StartF, Depth) end. -pp_fun(Enc) -> - P = modifier(Enc) ++ "p", +pp_fun({Enc,Depth}) -> + {Letter,Tl} = case Depth of + unlimited -> {"p",[]}; + _ -> {"P",[Depth]} + end, + P = modifier(Enc) ++ Letter, fun(Term, I) -> - io_lib:format("~." ++ integer_to_list(I) ++ P, [Term]) + io_lib:format("~." ++ integer_to_list(I) ++ P, [Term|Tl]) end. -format_tag(Tag, Data) -> - io_lib:format(" ~p: ~80.18p~n", [Tag, Data]). +format_tag(Tag, Data, {_Enc,Depth}) -> + case Depth of + unlimited -> + io_lib:format(" ~p: ~80.18p~n", [Tag, Data]); + _ -> + io_lib:format(" ~p: ~80.18P~n", [Tag, Data, Depth]) + end. modifier(latin1) -> ""; modifier(_) -> "t". diff --git a/lib/stdlib/test/proc_lib_SUITE.erl b/lib/stdlib/test/proc_lib_SUITE.erl index 437c981461..3a8fa74d36 100644 --- a/lib/stdlib/test/proc_lib_SUITE.erl +++ b/lib/stdlib/test/proc_lib_SUITE.erl @@ -28,7 +28,7 @@ init_per_group/2,end_per_group/2, crash/1, sync_start_nolink/1, sync_start_link/1, spawn_opt/1, sp1/0, sp2/0, sp3/1, sp4/2, sp5/1, - hibernate/1, stop/1]). + hibernate/1, stop/1, t_format/1]). -export([ otp_6345/1, init_dont_hang/1]). -export([hib_loop/1, awaken/1]). @@ -51,7 +51,7 @@ suite() -> [{ct_hooks,[ts_install_cth]}]. all() -> [crash, {group, sync_start}, spawn_opt, hibernate, - {group, tickets}, stop]. + {group, tickets}, stop, t_format]. groups() -> [{tickets, [], [otp_6345, init_dont_hang]}, @@ -457,6 +457,51 @@ system_terminate(crash,_Parent,_Deb,_State) -> system_terminate(Reason,_Parent,_Deb,_State) -> exit(Reason). + +t_format(_Config) -> + error_logger:tty(false), + try + t_format() + after + error_logger:tty(true) + end, + ok. + +t_format() -> + error_logger:add_report_handler(?MODULE, self()), + Pid = proc_lib:spawn(fun t_format_looper/0), + HugeData = gb_sets:from_list(lists:seq(1, 100)), + Pid ! {die,HugeData}, + Report = receive + {crash_report, Pid, Report0} -> Report0 + end, + Usz = do_test_format(Report, unlimited), + Tsz = do_test_format(Report, 20), + + if + Tsz >= Usz -> + ?t:fail(); + true -> + ok + end, + + ok. + +do_test_format(Report, Depth) -> + io:format("*** Depth = ~p", [Depth]), + S0 = proc_lib:format(Report, latin1, Depth), + S = lists:flatten(S0), + io:put_chars(S), + length(S). + +t_format_looper() -> + receive + {die,Data} -> + exit(Data); + _ -> + t_format_looper() + end. + %%----------------------------------------------------------------- %% The error_logger handler used. %%----------------------------------------------------------------- -- cgit v1.2.3