From 53850d6c310643393185819c179efd4b866943fe Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Mon, 22 Oct 2018 10:37:35 +0200 Subject: Print sys:log in error report --- lib/stdlib/src/gen_fsm.erl | 19 +++++++++--- lib/stdlib/src/gen_server.erl | 20 ++++++++++--- lib/stdlib/src/gen_statem.erl | 68 +++++++++++++++++++++++++++++-------------- lib/stdlib/src/sys.erl | 8 ++++- 4 files changed, 84 insertions(+), 31 deletions(-) (limited to 'lib/stdlib/src') diff --git a/lib/stdlib/src/gen_fsm.erl b/lib/stdlib/src/gen_fsm.erl index caaaf8fa2e..2e6721e2a1 100644 --- a/lib/stdlib/src/gen_fsm.erl +++ b/lib/stdlib/src/gen_fsm.erl @@ -610,16 +610,17 @@ terminate(Reason, Name, Msg, Mod, StateName, StateData, Debug) -> end. error_info(Reason, Name, Msg, StateName, StateData, Debug) -> + Log = [{Event, State} || {Event, State, _FormFunc} <- sys:get_log(Debug)], ?LOG_ERROR(#{label=>{gen_fsm,terminate}, name=>Name, last_message=>Msg, state_name=>StateName, state_data=>StateData, + log=>Log, reason=>Reason}, #{domain=>[otp], report_cb=>fun gen_fsm:format_log/1, error_logger=>#{tag=>error}}), - sys:print_log(Debug), ok. format_log(#{label:={gen_fsm,terminate}, @@ -627,6 +628,7 @@ format_log(#{label:={gen_fsm,terminate}, last_message:=Msg, state_name:=StateName, state_data:=StateData, + log:=Log, reason:=Reason}) -> Reason1 = case Reason of @@ -645,12 +647,21 @@ format_log(#{label:={gen_fsm,terminate}, _ -> Reason end, + LimitedLog = [error_logger:limit_term(D) || D <- Log], {"** State machine ~tp terminating \n" ++ get_msg_str(Msg) ++ "** When State == ~tp~n" "** Data == ~tp~n" - "** Reason for termination = ~n** ~tp~n", - [Name, get_msg(Msg), StateName, StateData, Reason1]}; + "** Reason for termination ==~n** ~tp~n" ++ + case LimitedLog of + [] -> []; + _ -> "** Log ==~n** ~tp~n" + end, + [Name, get_msg(Msg), StateName, StateData, Reason1 | + case LimitedLog of + [] -> []; + _ -> [LimitedLog] + end]}; format_log(#{label:={gen_fsm,no_handle_info}, module:=Mod, message:=Msg}) -> @@ -689,7 +700,7 @@ format_status(Opt, StatusData) -> StatusData, Header = gen:format_status_header("Status for state machine", Name), - Log = sys:get_debug(log, Debug, []), + Log = [{Ev, St} || {Ev, St, _FormFunc} <- sys:get_log(Debug)], Specfic = format_status(Opt, Mod, PDict, StateData), Specfic = case format_status(Opt, Mod, PDict, StateData) of S when is_list(S) -> S; diff --git a/lib/stdlib/src/gen_server.erl b/lib/stdlib/src/gen_server.erl index 44e9231ebe..7de62eaf01 100644 --- a/lib/stdlib/src/gen_server.erl +++ b/lib/stdlib/src/gen_server.erl @@ -885,16 +885,17 @@ error_info(_Reason, application_controller, _From, _Msg, _Mod, _State, _Debug) - %% of it instead ok; error_info(Reason, Name, From, Msg, Mod, State, Debug) -> + Log = [{Ev, St} || {Ev, St, _FormFunc} <- sys:get_log(Debug)], ?LOG_ERROR(#{label=>{gen_server,terminate}, name=>Name, last_message=>Msg, state=>format_status(terminate, Mod, get(), State), + log=>Log, reason=>Reason, client_info=>client_stacktrace(From)}, #{domain=>[otp], report_cb=>fun gen_server:format_log/1, error_logger=>#{tag=>error}}), - sys:print_log(Debug), ok. client_stacktrace(undefined) -> @@ -917,6 +918,7 @@ format_log(#{label:={gen_server,terminate}, name:=Name, last_message:=Msg, state:=State, + log:=Log, reason:=Reason, client_info:=Client}) -> Reason1 = @@ -937,11 +939,21 @@ format_log(#{label:={gen_server,terminate}, error_logger:limit_term(Reason) end, {ClientFmt,ClientArgs} = format_client_log(Client), + [LimitedState|LimitedLog] = + [error_logger:limit_term(D) || D <- [State|Log]], {"** Generic server ~tp terminating \n" "** Last message in was ~tp~n" "** When Server state == ~tp~n" - "** Reason for termination == ~n** ~tp~n" ++ ClientFmt, - [Name, Msg, error_logger:limit_term(State), Reason1] ++ ClientArgs}; + "** Reason for termination ==~n** ~tp~n" ++ + case LimitedLog of + [] -> []; + _ -> "** Log ==~n** ~tp~n" + end ++ ClientFmt, + [Name, Msg, LimitedState, Reason1] ++ + case LimitedLog of + [] -> []; + _ -> [LimitedLog] + end ++ ClientArgs}; format_log(#{label:={gen_server,no_handle_info}, module:=Mod, message:=Msg}) -> @@ -966,7 +978,7 @@ format_client_log({_From,{Name,Stacktrace}}) -> format_status(Opt, StatusData) -> [PDict, SysState, Parent, Debug, [Name, State, Mod, _Time, _HibernateAfterTimeout]] = StatusData, Header = gen:format_status_header("Status for generic server", Name), - Log = sys:get_debug(log, Debug, []), + Log = [{Ev, St} || {Ev, St, _FormFunc} <- sys:get_log(Debug)], Specfic = case format_status(Opt, Mod, PDict, State) of S when is_list(S) -> S; S -> [S] diff --git a/lib/stdlib/src/gen_statem.erl b/lib/stdlib/src/gen_statem.erl index 24b268cd38..016665ef35 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -586,7 +586,12 @@ enter_loop(Module, Opts, State, Data, Server_or_Actions) -> enter_loop(Module, Opts, State, Data, Server, Actions) -> is_atom(Module) orelse error({atom,Module}), Parent = gen:get_parent(), - enter(Module, Opts, State, Data, Server, Actions, Parent). + Name = gen:get_proc_name(Server), + Debug = gen:debug_options(Name, Opts), + HibernateAfterTimeout = gen:hibernate_after(Opts), + enter( + Parent, Debug, Module, Name, HibernateAfterTimeout, + State, Data, Actions). %%--------------------------------------------------------------------------- %% API helpers @@ -658,11 +663,10 @@ send(Proc, Msg) -> ok. %% Here the init_it/6 and enter_loop/5,6,7 functions converge -enter(Module, Opts, State, Data, Server, Actions, Parent) -> +enter( + Parent, Debug, Module, Name, HibernateAfterTimeout, + State, Data, Actions) -> %% The values should already have been type checked - Name = gen:get_proc_name(Server), - Debug = gen:debug_options(Name, Opts), - HibernateAfterTimeout = gen:hibernate_after(Opts), Events = [], Event = {internal,init_state}, %% We enforce {postpone,false} to ensure that @@ -695,18 +699,24 @@ enter(Module, Opts, State, Data, Server, Actions, Parent) -> init_it(Starter, self, ServerRef, Module, Args, Opts) -> init_it(Starter, self(), ServerRef, Module, Args, Opts); init_it(Starter, Parent, ServerRef, Module, Args, Opts) -> + Name = gen:get_proc_name(ServerRef), + Debug = gen:debug_options(Name, Opts), + HibernateAfterTimeout = gen:hibernate_after(Opts), try Module:init(Args) of Result -> - init_result(Starter, Parent, ServerRef, Module, Result, Opts) + init_result( + Starter, Parent, ServerRef, Module, Result, + Name, Debug, HibernateAfterTimeout) catch Result -> - init_result(Starter, Parent, ServerRef, Module, Result, Opts); + init_result( + Starter, Parent, ServerRef, Module, Result, + Name, Debug, HibernateAfterTimeout); Class:Reason:Stacktrace -> - Name = gen:get_proc_name(ServerRef), gen:unregister_name(ServerRef), proc_lib:init_ack(Starter, {error,Reason}), error_info( - Class, Reason, Stacktrace, + Class, Reason, Stacktrace, Debug, #state{name = Name}, []), erlang:raise(Class, Reason, Stacktrace) @@ -715,14 +725,20 @@ init_it(Starter, Parent, ServerRef, Module, Args, Opts) -> %%--------------------------------------------------------------------------- %% gen callbacks helpers -init_result(Starter, Parent, ServerRef, Module, Result, Opts) -> +init_result( + Starter, Parent, ServerRef, Module, Result, + Name, Debug, HibernateAfterTimeout) -> case Result of {ok,State,Data} -> proc_lib:init_ack(Starter, {ok,self()}), - enter(Module, Opts, State, Data, ServerRef, [], Parent); + enter( + Parent, Debug, Module, Name, HibernateAfterTimeout, + State, Data, []); {ok,State,Data,Actions} -> proc_lib:init_ack(Starter, {ok,self()}), - enter(Module, Opts, State, Data, ServerRef, Actions, Parent); + enter( + Parent, Debug, Module, Name, HibernateAfterTimeout, + State, Data, Actions); {stop,Reason} -> gen:unregister_name(ServerRef), proc_lib:init_ack(Starter, {error,Reason}), @@ -732,12 +748,11 @@ init_result(Starter, Parent, ServerRef, Module, Result, Opts) -> proc_lib:init_ack(Starter, ignore), exit(normal); _ -> - Name = gen:get_proc_name(ServerRef), gen:unregister_name(ServerRef), Error = {bad_return_from_init,Result}, proc_lib:init_ack(Starter, {error,Error}), error_info( - error, Error, ?STACKTRACE(), + error, Error, ?STACKTRACE(), Debug, #state{name = Name}, []), exit(Error) @@ -792,7 +807,7 @@ format_status( [PDict,SysState,Parent,Debug, #state{name = Name, postponed = P} = S]) -> Header = gen:format_status_header("Status for state machine", Name), - Log = sys:get_debug(log, Debug, []), + Log = [{Event, State} || {Event, State, _FormFunc} <- sys:get_log(Debug)], [{header,Header}, {data, [{"Status",SysState}, @@ -1877,8 +1892,7 @@ terminate( catch _ -> ok; C:R:ST -> - error_info(C, R, ST, S, Q), - sys:print_log(Debug), + error_info(C, R, ST, Debug, S, Q), erlang:raise(C, R, ST) end; false -> @@ -1893,8 +1907,7 @@ terminate( {shutdown,_} -> terminate_sys_debug(Debug, S, State, Reason); _ -> - error_info(Class, Reason, Stacktrace, S, Q), - sys:print_log(Debug) + error_info(Class, Reason, Stacktrace, Debug, S, Q) end, case Stacktrace of [] -> @@ -1908,13 +1921,14 @@ terminate_sys_debug(Debug, S, State, Reason) -> error_info( - Class, Reason, Stacktrace, + Class, Reason, Stacktrace, Debug, #state{ name = Name, callback_mode = CallbackMode, state_enter = StateEnter, postponed = P} = S, Q) -> + Log = [{Ev, St} || {Ev, St, _FormFunc} <- sys:get_log(Debug)], ?LOG_ERROR(#{label=>{gen_statem,terminate}, name=>Name, queue=>Q, @@ -1922,6 +1936,7 @@ error_info( callback_mode=>CallbackMode, state_enter=>StateEnter, state=>format_status(terminate, get(), S), + log=>Log, reason=>{Class,Reason,Stacktrace}}, #{domain=>[otp], report_cb=>fun gen_statem:format_log/1, @@ -1934,6 +1949,7 @@ format_log(#{label:={gen_statem,terminate}, callback_mode:=CallbackMode, state_enter:=StateEnter, state:=FmtData, + log:=Log, reason:={Class,Reason,Stacktrace}}) -> {FixedReason,FixedStacktrace} = case Stacktrace of @@ -1960,8 +1976,8 @@ format_log(#{label:={gen_statem,terminate}, end; _ -> {Reason,Stacktrace} end, - [LimitedP, LimitedFmtData, LimitedFixedReason] = - [error_logger:limit_term(D) || D <- [P, FmtData, FixedReason]], + [LimitedP, LimitedFmtData, LimitedFixedReason | LimitedLog] = + [error_logger:limit_term(D) || D <- [P, FmtData, FixedReason | Log]], CBMode = case StateEnter of true -> @@ -1988,6 +2004,10 @@ format_log(#{label:={gen_statem,terminate}, case FixedStacktrace of [] -> ""; _ -> "** Stacktrace =~n** ~tp~n" + end ++ + case LimitedLog of + [] -> ""; + _ -> "** Log =~n** ~tp~n" end, [Name | case Q of @@ -2008,6 +2028,10 @@ format_log(#{label:={gen_statem,terminate}, case FixedStacktrace of [] -> []; _ -> [FixedStacktrace] + end ++ + case LimitedLog of + [] -> []; + _ -> [LimitedLog] end}. %% Call Module:format_status/2 or return a default value diff --git a/lib/stdlib/src/sys.erl b/lib/stdlib/src/sys.erl index 8e12b3ff8d..6775dfe933 100644 --- a/lib/stdlib/src/sys.erl +++ b/lib/stdlib/src/sys.erl @@ -30,7 +30,7 @@ log_to_file/2, log_to_file/3, no_debug/1, no_debug/2, install/2, install/3, remove/2, remove/3]). -export([handle_system_msg/6, handle_system_msg/7, handle_debug/4, - print_log/1, get_debug/3, debug_options/1, suspend_loop_hib/6]). + print_log/1, get_log/1, get_debug/3, debug_options/1, suspend_loop_hib/6]). %%----------------------------------------------------------------- %% Types @@ -635,6 +635,12 @@ print_log(Debug) -> NLog = get_debug(log, Debug, nlog_new()), lists:foreach(fun print_event/1, nlog_get(NLog)). +-spec get_log(Debug) -> [system_event()] when + Debug :: [dbg_opt()]. +get_log(Debug) -> + NLog = get_debug(log, Debug, nlog_new()), + nlog_get(NLog). + close_log_file(Debug) -> case get_debug2(log_to_file, Debug, []) of [] -> -- cgit v1.2.3