diff options
-rw-r--r-- | lib/kernel/doc/src/kernel_app.xml | 37 | ||||
-rw-r--r-- | lib/sasl/doc/src/sasl_app.xml | 12 | ||||
-rw-r--r-- | lib/sasl/src/sasl_report.erl | 48 | ||||
-rw-r--r-- | lib/sasl/test/Makefile | 4 | ||||
-rw-r--r-- | lib/sasl/test/sasl_SUITE.erl | 97 | ||||
-rw-r--r-- | lib/sasl/test/sasl_report_SUITE.erl | 141 | ||||
-rw-r--r-- | lib/sasl/test/sasl_report_suite_supervisor.erl | 77 | ||||
-rw-r--r-- | lib/stdlib/doc/src/proc_lib.xml | 11 | ||||
-rw-r--r-- | lib/stdlib/src/error_logger_file_h.erl | 218 | ||||
-rw-r--r-- | lib/stdlib/src/error_logger_tty_h.erl | 237 | ||||
-rw-r--r-- | lib/stdlib/src/proc_lib.erl | 65 | ||||
-rw-r--r-- | lib/stdlib/test/Makefile | 1 | ||||
-rw-r--r-- | lib/stdlib/test/error_logger_h_SUITE.erl | 400 | ||||
-rw-r--r-- | lib/stdlib/test/proc_lib_SUITE.erl | 56 | ||||
-rw-r--r-- | lib/stdlib/test/zip_SUITE.erl | 20 |
15 files changed, 1154 insertions, 270 deletions
diff --git a/lib/kernel/doc/src/kernel_app.xml b/lib/kernel/doc/src/kernel_app.xml index 2cea38bae9..956c57f7c1 100644 --- a/lib/kernel/doc/src/kernel_app.xml +++ b/lib/kernel/doc/src/kernel_app.xml @@ -43,6 +43,7 @@ <item><c>erl_boot_server</c></item> <item><c>erl_ddll</c></item> <item><c>error_logger</c></item> + <item><c>error_logger_format_depth</c></item> <item><c>file</c></item> <item><c>global</c></item> <item><c>global_group</c></item> @@ -152,6 +153,42 @@ </item> </taglist> </item> + <tag><c>error_logger_format_depth = Depth</c></tag> + <item> + <marker id="error_logger_format_depth"></marker> + <p>This parameter can be used to limit the size of the + formatted output from the error logger event handlers.</p> + + <note><p>This configuration parameter was introduced in OTP 18.1. + It is currently experimental. Based on user feedback it + may be changed or improved in future releases, for example + to gain better control over how to limit the size of the + formatted output. We have no plans to entirely remove this + new feature, unless it turns out to be completely + useless. In OTP 19, the default may be changed to limit the + formatted output.</p></note> + + <p><c>Depth</c> is a positive integer that is the maximum + depth to which terms are printed by the error logger event + handlers included in OTP. Specifically, the two event handlers + defined by the <c>Kernel</c> application and the two event + handlers in the <c>SASL</c> application will use this + configuration parameter. (If you have implemented you own + error handlers, this configuration parameter will have no + effect on them.)</p> + + <p>The way <c>Depth</c> is used, is that format strings + string passed to the event handlers will be rewritten. + The "~p" and "~w" format controls will be replaced with + "~P" and "~W", respectively, and <c>Depth</c> will be + used as the depth parameter. See + <seealso marker="stdlib:io#format/2">io:format/2</seealso>.</p> + + <note><p>A reasonable starting value for <c>Depth</c> is + <c>30</c>. You should test crashing various processes in your + application and examine the logs from the crashes, and then + either increase or decrease the value.</p></note> + </item> <tag><c>global_groups = [GroupTuple]</c></tag> <item> <p>Defines global groups, see diff --git a/lib/sasl/doc/src/sasl_app.xml b/lib/sasl/doc/src/sasl_app.xml index 7cdb3e2ca7..fe38e69ce3 100644 --- a/lib/sasl/doc/src/sasl_app.xml +++ b/lib/sasl/doc/src/sasl_app.xml @@ -57,11 +57,19 @@ <taglist> <tag><c>sasl_report_tty_h</c></tag> <item> - <p>Formats and writes <em>supervisor reports</em>, <em>crash reports</em> and <em>progress reports</em> to <c>stdio</c>.</p> + <p>Formats and writes <em>supervisor reports</em>, <em>crash reports</em> and <em>progress reports</em> to <c>stdio</c>. + This error logger event handler will use + <seealso marker="kernel:kernel_app#error_logger_format_depth">error_logger_format_depth</seealso> + in the Kernel application to limit how much detail are printed to + for crash and supervisor reports.</p> </item> <tag><c>sasl_report_file_h</c></tag> <item> - <p>Formats and writes <em>supervisor reports</em>, <em>crash report</em> and <em>progress report</em> to a single file.</p> + <p>Formats and writes <em>supervisor reports</em>, <em>crash report</em> and <em>progress report</em> to a single file. + This error logger event handler will use + <seealso marker="kernel:kernel_app#error_logger_format_depth">error_logger_format_depth</seealso> + in the Kernel application to limit how much detail are printed to + for crash and supervisor reports.</p> </item> <tag><c>log_mf_h</c></tag> <item> diff --git a/lib/sasl/src/sasl_report.erl b/lib/sasl/src/sasl_report.erl index 1b1d432352..0b8c4212d2 100644 --- a/lib/sasl/src/sasl_report.erl +++ b/lib/sasl/src/sasl_report.erl @@ -62,27 +62,53 @@ write_report2(IO, Fd, Head, supervisor_report, Report) -> Context = sup_get(errorContext, Report), Reason = sup_get(reason, Report), Offender = sup_get(offender, Report), - FmtString = " Supervisor: ~p~n Context: ~p~n Reason: " - "~80.18p~n Offender: ~80.18p~n~n", - write_report_action(IO, Fd, Head ++ FmtString, - [Name,Context,Reason,Offender]); + {FmtString,Args} = supervisor_format([Name,Context,Reason,Offender]), + write_report_action(IO, Fd, Head, FmtString, Args); write_report2(IO, Fd, Head, progress, Report) -> Format = format_key_val(Report), - write_report_action(IO, Fd, Head ++ "~s", [Format]); + write_report_action(IO, Fd, Head, "~s", [Format]); write_report2(IO, Fd, Head, crash_report, Report) -> - Format = proc_lib:format(Report), - write_report_action(IO, Fd, Head ++ "~s", [Format]). + Depth = get_depth(), + Format = proc_lib:format(Report, latin1, Depth), + write_report_action(IO, Fd, Head, "~s", [Format]). + +supervisor_format(Args0) -> + case get_depth() of + unlimited -> + {" Supervisor: ~p~n" + " Context: ~p~n" + " Reason: ~80.18p~n" + " Offender: ~80.18p~n~n", + Args0}; + Depth -> + [A,B,C,D] = Args0, + Args = [A,Depth,B,Depth,C,Depth,D,Depth], + {" Supervisor: ~P~n" + " Context: ~P~n" + " Reason: ~80.18P~n" + " Offender: ~80.18P~n~n", + Args} + end. -write_report_action(io, Fd, Format, Args) -> - io:format(Fd, Format, Args); -write_report_action(io_lib, _Fd, Format, Args) -> - io_lib:format(Format, Args). +write_report_action(IO, Fd, Head, Format, Args) -> + S = [Head|io_lib:format(Format, Args)], + case IO of + io -> io:put_chars(Fd, S); + io_lib -> S + end. format_key_val([{Tag,Data}|Rep]) -> io_lib:format(" ~16w: ~p~n",[Tag,Data]) ++ format_key_val(Rep); format_key_val(_) -> []. +get_depth() -> + case application:get_env(kernel, error_logger_format_depth) of + {ok, Depth} when is_integer(Depth) -> + max(10, Depth); + undefined -> + unlimited + end. sup_get(Tag, Report) -> case lists:keysearch(Tag, 1, Report) of diff --git a/lib/sasl/test/Makefile b/lib/sasl/test/Makefile index 86fc57abfc..86976def6a 100644 --- a/lib/sasl/test/Makefile +++ b/lib/sasl/test/Makefile @@ -29,11 +29,13 @@ MODULES= \ alarm_handler_SUITE \ installer \ release_handler_SUITE \ + sasl_report_SUITE \ + sasl_report_suite_supervisor \ systools_SUITE \ systools_rc_SUITE \ overload_SUITE \ rb_SUITE \ - rh_test_lib + rh_test_lib \ ERL_FILES= $(MODULES:%=%.erl) diff --git a/lib/sasl/test/sasl_SUITE.erl b/lib/sasl/test/sasl_SUITE.erl index 1d76cdee6e..cd8316b451 100644 --- a/lib/sasl/test/sasl_SUITE.erl +++ b/lib/sasl/test/sasl_SUITE.erl @@ -28,10 +28,11 @@ -export([app_test/1, appup_test/1, log_mf_h_env/1, - log_file/1]). + log_file/1, + utc_log/1]). all() -> - [log_mf_h_env, log_file, app_test, appup_test]. + [log_mf_h_env, log_file, app_test, appup_test, utc_log]. groups() -> []. @@ -182,20 +183,104 @@ log_mf_h_env(Config) -> log_file(Config) -> PrivDir = ?config(priv_dir,Config), LogDir = filename:join(PrivDir,sasl_SUITE_log_dir), - ok = filelib:ensure_dir(LogDir), File = filename:join(LogDir, "file.log"), + ok = filelib:ensure_dir(File), application:stop(sasl), clear_env(sasl), - ok = application:set_env(sasl,sasl_error_logger,{file, File}, [{persistent, true}]), + _ = test_log_file(File, {file,File}), + _ = test_log_file(File, {file,File,[write]}), + + ok = file:write_file(File, <<"=PROGRESS preserve me\n">>), + <<"=PROGRESS preserve me\n",_/binary>> = + test_log_file(File, {file,File,[append]}), + + ok = application:set_env(sasl,sasl_error_logger, tty, + [{persistent, false}]), + ok = application:start(sasl). + +test_log_file(File, Arg) -> + ok = application:set_env(sasl, sasl_error_logger, Arg, + [{persistent, true}]), + ok = application:start(sasl), + application:stop(sasl), + {ok,Bin} = file:read_file(File), + ok = file:delete(File), + Lines0 = binary:split(Bin, <<"\n">>, [trim_all,global]), + Lines = [L || L <- Lines0, + binary:match(L, <<"=PROGRESS">>) =:= {0,9}], + io:format("~p:\n~p\n", [Arg,Lines]), + + %% There must be at least four PROGRESS lines. + if + length(Lines) >= 4 -> ok; + true -> ?t:fail() + end, + Bin. + +%% Make a basic test of utc_log. +utc_log(Config) -> + PrivDir = ?config(priv_dir, Config), + LogDir = filename:join(PrivDir, sasl_SUITE_log_dir), + Log = filename:join(LogDir, "utc.log"), + ok = filelib:ensure_dir(Log), + + application:stop(sasl), + clear_env(sasl), + + %% Test that the UTC marker gets added to PROGRESS lines + %% when the utc_log configuration variable is set to true. + ok = application:set_env(sasl, sasl_error_logger, {file,Log}, + [{persistent,true}]), + ok = application:set_env(sasl, utc_log, true, [{persistent,true}]), ok = application:start(sasl), application:stop(sasl), - ok = application:set_env(sasl,sasl_error_logger,{file, File, [append]}, [{persistent, true}]), + + verify_utc_log(Log, true), + + %% Test that no UTC markers gets added to PROGRESS lines + %% when the utc_log configuration variable is set to false. + ok = application:set_env(sasl, utc_log, false, [{persistent,true}]), + ok = application:start(sasl), + application:stop(sasl), + + verify_utc_log(Log, false), + + %% Test that no UTC markers gets added to PROGRESS lines + %% when the utc_log configuration variable is unset. + ok = application:unset_env(sasl, utc_log, [{persistent,true}]), ok = application:start(sasl), application:stop(sasl), - ok = application:set_env(sasl,sasl_error_logger, tty, [{persistent, false}]), + + verify_utc_log(Log, false), + + %% Change back to the standard TTY error logger. + ok = application:set_env(sasl,sasl_error_logger, tty, + [{persistent, false}]), ok = application:start(sasl). +verify_utc_log(Log, UTC) -> + {ok,Bin} = file:read_file(Log), + ok = file:delete(Log), + + Lines0 = binary:split(Bin, <<"\n">>, [trim_all,global]), + Lines = [L || L <- Lines0, + binary:match(L, <<"=PROGRESS">>) =:= {0,9}], + Setting = application:get_env(sasl, utc_log), + io:format("utc_log ~p:\n~p\n", [Setting,Lines]), + Filtered = [L || L <- Lines, + binary:match(L, <<" UTC ===">>) =:= nomatch], + %% Filtered now contains all lines WITHOUT any UTC markers. + case UTC of + false -> + %% No UTC marker on the PROGRESS line. + Filtered = Lines; + true -> + %% Each PROGRESS line must have an UTC marker. + [] = Filtered + end, + ok. + %%----------------------------------------------------------------- %% Internal diff --git a/lib/sasl/test/sasl_report_SUITE.erl b/lib/sasl/test/sasl_report_SUITE.erl new file mode 100644 index 0000000000..940234f152 --- /dev/null +++ b/lib/sasl/test/sasl_report_SUITE.erl @@ -0,0 +1,141 @@ +%% +%% %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(sasl_report_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([gen_server_crash/1]). + +-export([crash_me/0,start_link/0,init/1,handle_cast/2,terminate/2]). + +-include_lib("test_server/include/test_server.hrl"). + +suite() -> [{ct_hooks,[ts_install_cth]}]. + +all() -> + [gen_server_crash]. + +groups() -> + []. + +init_per_suite(Config) -> + Config. + +end_per_suite(_Config) -> + ok. + +init_per_group(_GroupName, Config) -> + Config. + +end_per_group(_GroupName, Config) -> + Config. + +gen_server_crash(Config) -> + try + do_gen_server_crash(Config) + after + error_logger:tty(true), + ok = application:unset_env(sasl, sasl_error_logger), + ok = application:unset_env(kernel, error_logger_format_depth), + error_logger:add_report_handler(cth_log_redirect) + end, + ok. + +do_gen_server_crash(Config) -> + PrivDir = ?config(priv_dir, Config), + LogDir = filename:join(PrivDir, ?MODULE), + KernelLog = filename:join(LogDir, "kernel.log"), + SaslLog = filename:join(LogDir, "sasl.log"), + ok = filelib:ensure_dir(SaslLog), + + error_logger:delete_report_handler(cth_log_redirect), + error_logger:tty(false), + application:stop(sasl), + ok = application:set_env(sasl, sasl_error_logger, {file,SaslLog}, + [{persistent,true}]), + application:set_env(kernel, error_logger_format_depth, 30), + error_logger:logfile({open,KernelLog}), + application:start(sasl), + io:format("~p\n", [gen_event:which_handlers(error_logger)]), + + crash_me(), + + error_logger:logfile(close), + + check_file(KernelLog, 70000, 150000), + check_file(SaslLog, 50000, 100000), + + ok. + +check_file(File, Min, Max) -> + {ok,Bin} = file:read_file(File), + Base = filename:basename(File), + io:format("*** Contents of ~s ***\n", [Base]), + io:put_chars([Bin,"\n"]), + Sz = byte_size(Bin), + io:format("Size: ~p (allowed range is ~p..~p)\n", + [Sz,Min,Max]), + if + Sz < Min -> + %% Truncated? Other problem? + ?t:fail({too_short,Base}); + Sz > Max -> + %% Truncation doesn't work? + ?t:fail({too_big,Base}); + true -> + ok + end. + +%%% +%%% gen_server that crashes. +%%% + +crash_me() -> + {ok,SuperPid} = supervisor:start_link(sasl_report_suite_supervisor, []), + [{Id,Pid,_,_}] = supervisor:which_children(SuperPid), + HugeData = gb_sets:from_list(lists:seq(1, 100000)), + gen_server:cast(Pid, HugeData), + Ref = monitor(process, Pid), + receive + {'DOWN',Ref,process,Pid,_} -> + supervisor:terminate_child(SuperPid, Id), + unlink(SuperPid), + exit(SuperPid, kill), + ok + end. + +start_link() -> + gen_server:start_link(?MODULE, [], []). + +init(_) -> + St = <<0:100000/unit:8>>, + {ok,St}. + +handle_cast(Big, St) -> + Seq = lists:seq(1, 10000), + self() ! Seq, + self() ! Seq, + self() ! Seq, + self() ! Seq, + self() ! Seq, + x = Big, + {noreply,St}. + +terminate(_, _) -> + ok. diff --git a/lib/sasl/test/sasl_report_suite_supervisor.erl b/lib/sasl/test/sasl_report_suite_supervisor.erl new file mode 100644 index 0000000000..bc92a40af2 --- /dev/null +++ b/lib/sasl/test/sasl_report_suite_supervisor.erl @@ -0,0 +1,77 @@ +%% +%% %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(sasl_report_suite_supervisor). + +-behaviour(supervisor). + +%% API +-export([start_link/0]). + +%% Supervisor callbacks +-export([init/1]). + +-define(SERVER, ?MODULE). + +%%%=================================================================== +%%% API functions +%%%=================================================================== + +%%-------------------------------------------------------------------- +%% @doc +%% Starts the supervisor +%% +%% @spec start_link() -> {ok, Pid} | ignore | {error, Error} +%% @end +%%-------------------------------------------------------------------- +start_link() -> + supervisor:start_link({local, ?SERVER}, ?MODULE, []). + +%%%=================================================================== +%%% Supervisor callbacks +%%%=================================================================== + +%%-------------------------------------------------------------------- +%% @private +%% @doc +%% Whenever a supervisor is started using supervisor:start_link/[2,3], +%% this function is called by the new process to find out about +%% restart strategy, maximum restart intensity, and child +%% specifications. +%% +%% @spec init(Args) -> {ok, {SupFlags, [ChildSpec]}} | +%% ignore | +%% {error, Reason} +%% @end +%%-------------------------------------------------------------------- +init([]) -> + + SupFlags = #{strategy => one_for_one, + intensity => 1, + period => 5}, + + AChild = #{id => 'sasl_report_suit_supervisor', + start => {sasl_report_SUITE, start_link, []}, + restart => permanent, + shutdown => 5000, + type => worker, + modules => [sasl_report_SUITE]}, + + {ok, {SupFlags, [AChild]}}. 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 @@ -227,6 +227,17 @@ init(Parent) -> </desc> </func> <func> + <name name="format" arity="3"/> + <fsummary>Format a crash report.</fsummary> + <desc> + <p>This function can be used by a user defined event handler to + format a crash report. When <anno>Depth</anno> is given as an + positive integer, it will be used in the format string to + limit the output as follows: <c>io_lib:format("~P", + [Term,<anno>Depth</anno>])</c>.</p> + </desc> + </func> + <func> <name name="initial_call" arity="1"/> <fsummary>Extract the initial call of a <c>proc_lib</c>spawned process.</fsummary> <desc> diff --git a/lib/stdlib/src/error_logger_file_h.erl b/lib/stdlib/src/error_logger_file_h.erl index a7f3615972..48c471924e 100644 --- a/lib/stdlib/src/error_logger_file_h.erl +++ b/lib/stdlib/src/error_logger_file_h.erl @@ -24,24 +24,28 @@ %%% %%% 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, handle_event/2, handle_call/2, handle_info/2, terminate/2, code_change/3]). +-record(st, + {fd, + filename, + 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}}) -> 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; @@ -53,38 +57,40 @@ init(File, PrevHandler) -> process_flag(trap_exit, true), case file:open(File, [write]) of {ok,Fd} -> - {ok, {Fd, File, 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, {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; _ -> {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}. -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}. @@ -104,69 +110,73 @@ 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 format(State, Format, Args) of + S0 -> + S0 + catch + _:_ -> + format(State, "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, {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), - 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. +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}}) -> + {"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 @@ -183,30 +193,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_term(Term) -> + [{"~p\n",[Term]}]. -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_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) -> @@ -222,15 +229,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)]); diff --git a/lib/stdlib/src/error_logger_tty_h.erl b/lib/stdlib/src/error_logger_tty_h.erl index 65ea645bd9..d2df6681e3 100644 --- a/lib/stdlib/src/error_logger_tty_h.erl +++ b/lib/stdlib/src/error_logger_tty_h.erl @@ -23,145 +23,180 @@ %%% %%% 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, 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, + depth=unlimited}). %% 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}}; + 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 %% 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, []}}. + 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}; 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({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}. 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). + +write_event(Event, IoMod, Depth) -> + do_write_event(#st{io_mod=IoMod,depth=Depth}, 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, {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), - 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 format(State, Format, Args) of + S0 -> + S0 + catch + _:_ -> + 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}}) -> + {"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; @@ -177,33 +212,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; @@ -227,7 +255,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)]); 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/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..b0b9c717a1 --- /dev/null +++ b/lib/stdlib/test/error_logger_h_SUITE.erl @@ -0,0 +1,400 @@ +%% +%% %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,logfile_truncated/1,tty/1,tty_truncated/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,logfile_truncated,tty,tty_truncated]. + +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(), + + do_one_logfile(Log, Ev, unlimited), + + 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], 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), + Log = filename:join(LogDir, "tty.log"), + ok = filelib:ensure_dir(Log), + + Ev = event_templates(), + + do_one_tty(Log, Ev, unlimited), + + 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], unlimited), + + test_server:stop_node(Node), + + 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), + tty_log_close(), + analyse_events(Log, Ev, [], Depth). + +tty_log_open(Log) -> + {ok,Fd} = file:open(Log, [write]), + 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() -> + 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]]}, + + %% 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()]), + 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, Depth) -> + {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, Depth), + 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, Depth) -> + try match_item(Item, Lines0, AtNode, Depth) of + Lines -> + match_output(T, Lines, AtNode, Depth) + 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, Depth) -> + case item_type(Item) of + {msg,Head,Args} -> + match_format(Head, Args, Lines, AtNode, Depth); + {report,Head,Args} -> + match_term(Head, Args, Lines, AtNode, Depth) + 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, Depth) -> + match_head(Tag, Head), + Bin = try dl_format(Depth, Format, Args) of + Str -> + iolist_to_binary(Str) + catch + _:_ -> + S = dl_format(Depth, "ERROR: ~p - ~p~n", [Format,Args]), + iolist_to_binary(S) + end, + Expected0 = binary:split(Bin, <<"\n">>, [global,trim]), + Expected = Expected0 ++ AtNode, + match_term_lines(Expected, Lines). + +match_term(Tag, [Arg], [Head|Lines], AtNode, Depth) -> + match_head(Tag, Head), + Expected0 = match_term_get_expected(Arg, Depth), + Expected = Expected0 ++ AtNode, + match_term_lines(Expected, Lines). + +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), + binary:split(Bin, <<"\n">>, [global,trim]). + +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); +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. + + +%% 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 +%%% calling error_logger_tty_h:write_event/2. +%%% + +init({_,_}=St) -> + {ok,St}. + +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,St}. + +terminate(_Reason, {Fd,_}) -> + ok = file:close(Fd), + []. + +tag_event(Event) -> + {erlang:universaltime(),Event}. diff --git a/lib/stdlib/test/proc_lib_SUITE.erl b/lib/stdlib/test/proc_lib_SUITE.erl index 36f009eec6..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]}, @@ -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) -> @@ -452,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. %%----------------------------------------------------------------- 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) -> []; |