From 785e6c73a586b0978953bf2457fab514c9dc8207 Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Thu, 18 Oct 2018 16:56:22 +0200 Subject: Fix sys:log functionality Abstract out Latest-N-Log functions to this to nlog_*. Fix sys:log(Name, get) to strip the internal formatting funs. --- lib/stdlib/src/sys.erl | 50 +++++++++++++++++++++++++++++++++++--------------- 1 file changed, 35 insertions(+), 15 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/sys.erl b/lib/stdlib/src/sys.erl index 0064414d6f..8f654841b6 100644 --- a/lib/stdlib/src/sys.erl +++ b/lib/stdlib/src/sys.erl @@ -388,9 +388,9 @@ handle_system_msg(SysState, Msg, From, Parent, Mod, Debug, Misc, Hib) -> handle_debug([{trace, true} | T], FormFunc, State, Event) -> print_event({Event, State, FormFunc}), [{trace, true} | handle_debug(T, FormFunc, State, Event)]; -handle_debug([{log, {N, LogData}} | T], FormFunc, State, Event) -> - NLogData = [{Event, State, FormFunc} | trim(N, LogData)], - [{log, {N, NLogData}} | handle_debug(T, FormFunc, State, Event)]; +handle_debug([{log, NLog} | T], FormFunc, State, Event) -> + Item = {Event, State, FormFunc}, + [{log, nlog_put(Item, NLog)} | handle_debug(T, FormFunc, State, Event)]; handle_debug([{log_to_file, Fd} | T], FormFunc, State, Event) -> print_event(Fd, {Event, State, FormFunc}), [{log_to_file, Fd} | handle_debug(T, FormFunc, State, Event)]; @@ -526,19 +526,19 @@ debug_cmd({trace, true}, Debug) -> debug_cmd({trace, false}, Debug) -> {ok, remove_debug(trace, Debug)}; debug_cmd({log, true}, Debug) -> - {_N, Logs} = get_debug(log, Debug, {0, []}), - {ok, install_debug(log, {10, trim(10, Logs)}, Debug)}; -debug_cmd({log, {true, N}}, Debug) when is_integer(N), N > 0 -> - {_N, Logs} = get_debug(log, Debug, {0, []}), - {ok, install_debug(log, {N, trim(N, Logs)}, Debug)}; + NLog = get_debug(log, Debug, nlog_new()), + {ok, install_debug(log, nlog_new(NLog), Debug)}; +debug_cmd({log, {true, N}}, Debug) when is_integer(N), 1 =< N -> + NLog = get_debug(log, Debug, nlog_new(N)), + {ok, install_debug(log, nlog_new(N, NLog), Debug)}; debug_cmd({log, false}, Debug) -> {ok, remove_debug(log, Debug)}; debug_cmd({log, print}, Debug) -> print_log(Debug), {ok, Debug}; debug_cmd({log, get}, Debug) -> - {_N, Logs} = get_debug(log, Debug, {0, []}), - {{ok, lists:reverse(Logs)}, Debug}; + NLog = get_debug(log, Debug, nlog_new()), + {{ok, nlog_get(NLog)}, Debug}; debug_cmd({log_to_file, false}, Debug) -> NDebug = close_log_file(Debug), {ok, NDebug}; @@ -625,9 +625,8 @@ get_debug2(Item, Debug, Default) -> -spec print_log(Debug) -> 'ok' when Debug :: [dbg_opt()]. print_log(Debug) -> - {_N, Logs} = get_debug(log, Debug, {0, []}), - lists:foreach(fun print_event/1, - lists:reverse(Logs)). + NLog = get_debug(log, Debug, nlog_new()), + lists:foreach(fun print_event/1, nlog_get(NLog)). close_log_file(Debug) -> case get_debug2(log_to_file, Debug, []) of @@ -638,6 +637,27 @@ close_log_file(Debug) -> remove_debug(log_to_file, Debug) end. +%%----------------------------------------------------------------- +%% Keep the last N Log functions +%%----------------------------------------------------------------- + +nlog_new() -> + nlog_new(10). +%% +nlog_new(N) when is_integer(N) -> + {N, []}; +nlog_new(NLog) -> + nlog_new(10, NLog). +%% +nlog_new(NewN, {_N, R}) -> + {NewN, trim(NewN, R)}. + +nlog_put(Item, {N, R}) -> + {N, [Item | trim(N, R)]}. + +nlog_get({_N, R}) -> + lists:reverse(R). + %%----------------------------------------------------------------- %% Func: debug_options/1 %% Purpose: Initiate a debug structure. Called by a process that @@ -665,9 +685,9 @@ debug_options(Options) -> debug_options([trace | T], Debug) -> debug_options(T, install_debug(trace, true, Debug)); debug_options([log | T], Debug) -> - debug_options(T, install_debug(log, {10, []}, Debug)); + debug_options(T, install_debug(log, nlog_new(), Debug)); debug_options([{log, N} | T], Debug) when is_integer(N), N > 0 -> - debug_options(T, install_debug(log, {N, []}, Debug)); + debug_options(T, install_debug(log, nlog_new(N), Debug)); debug_options([statistics | T], Debug) -> debug_options(T, install_debug(statistics, init_stat(), Debug)); debug_options([{log_to_file, FileName} | T], Debug) -> -- cgit v1.2.3 From 6f0a9a08023ea4825dbdcefae0d976b08566729a Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Mon, 29 Oct 2018 20:31:48 +0100 Subject: Optimize sys:log --- lib/stdlib/src/sys.erl | 68 +++++++++++++++++++++++++++++++++++++++++--------- 1 file changed, 56 insertions(+), 12 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/sys.erl b/lib/stdlib/src/sys.erl index 8f654841b6..7b161460b0 100644 --- a/lib/stdlib/src/sys.erl +++ b/lib/stdlib/src/sys.erl @@ -595,9 +595,6 @@ stat({out, _Msg, _To}, {Time, Reds, In, Out}) -> {Time, Reds, In, Out+1}; stat({out, _Msg, _To, _State}, {Time, Reds, In, Out}) -> {Time, Reds, In, Out+1}; stat(_, StatData) -> StatData. -trim(N, LogData) -> - lists:sublist(LogData, 1, N-1). - %%----------------------------------------------------------------- %% Debug structure manipulating functions %%----------------------------------------------------------------- @@ -640,22 +637,69 @@ close_log_file(Debug) -> %%----------------------------------------------------------------- %% Keep the last N Log functions %%----------------------------------------------------------------- +%% +%% Streamlined Okasaki queue as base for "keep the last N" log. +%% +%% To the reverse list head we cons new items. +%% The forward list contains elements in insertion order, +%% so the head is the oldest and the one to drop off +%% when the log is full. +%% +%% Here is how we can get away with only using one cons cell +%% to wrap the forward and reverse list, and the log size: +%% +%% A full log does not need a counter; we just cons one +%% and drop one: +%% +%% [ReverseList|ForwardList] +%% +%% A non-full log is filling up to N elements; +%% use a down counter instead of a list as first element: +%% +%% [RemainingToFullCount|ReverseList] nlog_new() -> nlog_new(10). %% -nlog_new(N) when is_integer(N) -> - {N, []}; -nlog_new(NLog) -> - nlog_new(10, NLog). +nlog_new([_|_] = NLog) -> + nlog_new(10, NLog); +nlog_new(N) -> + [N]. % Empty log size N >= 1 %% -nlog_new(NewN, {_N, R}) -> - {NewN, trim(NewN, R)}. +nlog_new(N, NLog) -> + lists:foldl( + fun (Item, NL) -> nlog_put(Item, NL) end, + nlog_new(N), + nlog_get(NLog)). -nlog_put(Item, {N, R}) -> - {N, [Item | trim(N, R)]}. +%% +nlog_put(Item, NLog) -> + case NLog of + [R|FF] when is_list(R) -> + %% Full log + case FF of + [_|F] -> + %% Cons to reverse list, drop from forward list + [[Item|R]|F]; + [] -> + %% Create new forward list from reverse list, + %% create new empty reverse list + [_|F] = lists:reverse(R, [Item]), + [[]|F] + end; + [1|R] -> + %% Log now gets full + [[Item|R]]; + [J|R] -> + %% Filling up to N elements + [J - 1,Item|R] + end. -nlog_get({_N, R}) -> +nlog_get([[]|F]) -> + F; +nlog_get([[_|_] = R|F]) -> + F ++ lists:reverse(R); +nlog_get([_J|R]) -> lists:reverse(R). %%----------------------------------------------------------------- -- cgit v1.2.3 From 156a1af989f4977eb68e4c64feb79c55f2a0855d Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Tue, 23 Oct 2018 15:55:50 +0200 Subject: Optimize sys:handle_debug/4 --- lib/stdlib/src/sys.erl | 30 ++++++++++++++++++++---------- 1 file changed, 20 insertions(+), 10 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/sys.erl b/lib/stdlib/src/sys.erl index 7b161460b0..8e12b3ff8d 100644 --- a/lib/stdlib/src/sys.erl +++ b/lib/stdlib/src/sys.erl @@ -385,31 +385,41 @@ handle_system_msg(SysState, Msg, From, Parent, Mod, Debug, Misc, Hib) -> FormFunc :: format_fun(), Extra :: term(), Event :: system_event(). -handle_debug([{trace, true} | T], FormFunc, State, Event) -> +handle_debug([{trace, true} = DbgOpt | T], FormFunc, State, Event) -> print_event({Event, State, FormFunc}), - [{trace, true} | handle_debug(T, FormFunc, State, Event)]; + [DbgOpt | handle_debug(T, FormFunc, State, Event)]; handle_debug([{log, NLog} | T], FormFunc, State, Event) -> Item = {Event, State, FormFunc}, [{log, nlog_put(Item, NLog)} | handle_debug(T, FormFunc, State, Event)]; -handle_debug([{log_to_file, Fd} | T], FormFunc, State, Event) -> +handle_debug([{log_to_file, Fd} = DbgOpt | T], FormFunc, State, Event) -> print_event(Fd, {Event, State, FormFunc}), - [{log_to_file, Fd} | handle_debug(T, FormFunc, State, Event)]; + [DbgOpt | handle_debug(T, FormFunc, State, Event)]; handle_debug([{statistics, StatData} | T], FormFunc, State, Event) -> NStatData = stat(Event, StatData), [{statistics, NStatData} | handle_debug(T, FormFunc, State, Event)]; handle_debug([{FuncId, {Func, FuncState}} | T], FormFunc, State, Event) -> - case catch Func(FuncState, Event, State) of + try Func(FuncState, Event, State) of done -> handle_debug(T, FormFunc, State, Event); - {'EXIT', _} -> handle_debug(T, FormFunc, State, Event); NFuncState -> - [{FuncId, {Func, NFuncState}} | handle_debug(T, FormFunc, State, Event)] + [{FuncId, {Func, NFuncState}} | + handle_debug(T, FormFunc, State, Event)] + catch + done -> handle_debug(T, FormFunc, State, Event); + NFuncState -> + [{FuncId, {Func, NFuncState}} | + handle_debug(T, FormFunc, State, Event)]; + _:_ -> handle_debug(T, FormFunc, State, Event) end; handle_debug([{Func, FuncState} | T], FormFunc, State, Event) -> - case catch Func(FuncState, Event, State) of + try Func(FuncState, Event, State) of done -> handle_debug(T, FormFunc, State, Event); - {'EXIT', _} -> handle_debug(T, FormFunc, State, Event); - NFuncState -> + NFuncState -> [{Func, NFuncState} | handle_debug(T, FormFunc, State, Event)] + catch + done -> handle_debug(T, FormFunc, State, Event); + NFuncState -> + [{Func, NFuncState} | handle_debug(T, FormFunc, State, Event)]; + _:_ -> handle_debug(T, FormFunc, State, Event) end; handle_debug([], _FormFunc, _State, _Event) -> []. -- cgit v1.2.3 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 ++- lib/stdlib/test/gen_statem_SUITE.erl | 43 ++++++++++---- lib/stdlib/test/stdlib_bench_SUITE.erl | 57 ++++++++++++------ .../stdlib_bench_SUITE_data/generic_server.erl | 4 +- .../stdlib_bench_SUITE_data/generic_statem.erl | 4 +- 8 files changed, 158 insertions(+), 65 deletions(-) (limited to 'lib') 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 [] -> diff --git a/lib/stdlib/test/gen_statem_SUITE.erl b/lib/stdlib/test/gen_statem_SUITE.erl index 017939fdd6..16cf8f43f9 100644 --- a/lib/stdlib/test/gen_statem_SUITE.erl +++ b/lib/stdlib/test/gen_statem_SUITE.erl @@ -513,7 +513,9 @@ abnormal1dirty(Config) -> %% trap exit since we must link to get the real bad_return_ error abnormal2(Config) -> OldFl = process_flag(trap_exit, true), - {ok,Pid} = gen_statem:start_link(?MODULE, start_arg(Config, []), []), + {ok,Pid} = + gen_statem:start_link( + ?MODULE, start_arg(Config, []), [{debug,[log]}]), %% bad return value in the gen_statem loop {{{bad_return_from_state_function,badreturn},_},_} = @@ -531,7 +533,9 @@ abnormal2(Config) -> %% trap exit since we must link to get the real bad_return_ error abnormal3(Config) -> OldFl = process_flag(trap_exit, true), - {ok,Pid} = gen_statem:start_link(?MODULE, start_arg(Config, []), []), + {ok,Pid} = + gen_statem:start_link( + ?MODULE, start_arg(Config, []), [{debug,[log]}]), %% bad return value in the gen_statem loop {{{bad_action_from_state_function,badaction},_},_} = @@ -549,7 +553,9 @@ abnormal3(Config) -> %% trap exit since we must link to get the real bad_return_ error abnormal4(Config) -> OldFl = process_flag(trap_exit, true), - {ok,Pid} = gen_statem:start_link(?MODULE, start_arg(Config, []), []), + {ok,Pid} = + gen_statem:start_link( + ?MODULE, start_arg(Config, []), [{debug,[log]}]), %% bad return value in the gen_statem loop BadTimeout = {badtimeout,4711,ouch}, @@ -689,7 +695,10 @@ state_enter(_Config) -> end}, {ok,STM} = gen_statem:start_link( - ?MODULE, {map_statem,Machine,[state_enter]}, [{debug,[trace]}]), + ?MODULE, {map_statem,Machine,[state_enter]}, + [{debug,[trace,{log,17}]}]), + ok = sys:log(STM, false), + ok = sys:log(STM, true), [{1,enter,start,start}] = flush(), {2,echo,start} = gen_statem:call(STM, echo), @@ -708,6 +717,11 @@ state_enter(_Config) -> {13,internal,start,wait}] = flush(), {14,repeat,start} = gen_statem:call(STM, repeat), [{15,enter,start,start}] = flush(), + + {ok,Log} = sys:log(STM, get), + io:format("sys:log ~p~n", [Log]), + ok = sys:log(STM, print), + {16,stop} = gen_statem:call(STM, {stop,bye}), [{'EXIT',STM,bye}] = flush(), @@ -1470,7 +1484,8 @@ enter_loop(_Config) -> %% Locally registered process + {local,Name} {ok,Pid1a} = - proc_lib:start_link(?MODULE, enter_loop, [local,local]), + proc_lib:start_link( + ?MODULE, enter_loop, [local,local,[{debug,[{log,7}]}]]), yes = gen_statem:call(Pid1a, 'alive?'), stopped = gen_statem:call(Pid1a, stop), receive @@ -1482,7 +1497,8 @@ enter_loop(_Config) -> %% Unregistered process + {local,Name} {ok,Pid1b} = - proc_lib:start_link(?MODULE, enter_loop, [anon,local]), + proc_lib:start_link( + ?MODULE, enter_loop, [anon,local,[{debug,[log]}]]), receive {'EXIT',Pid1b,process_not_registered} -> ok @@ -1591,6 +1607,9 @@ enter_loop(_Config) -> ok = verify_empty_msgq(). enter_loop(Reg1, Reg2) -> + enter_loop(Reg1, Reg2, []). +%% +enter_loop(Reg1, Reg2, Opts) -> process_flag(trap_exit, true), case Reg1 of local -> register(armitage, self()); @@ -1602,15 +1621,15 @@ enter_loop(Reg1, Reg2) -> case Reg2 of local -> gen_statem:enter_loop( - ?MODULE, [], state0, [], {local,armitage}); + ?MODULE, Opts, state0, [], {local,armitage}); global -> gen_statem:enter_loop( - ?MODULE, [], state0, [], {global,armitage}); + ?MODULE, Opts, state0, [], {global,armitage}); via -> gen_statem:enter_loop( - ?MODULE, [], state0, [], {via, dummy_via, armitage}); + ?MODULE, Opts, state0, [], {via, dummy_via, armitage}); anon -> - gen_statem:enter_loop(?MODULE, [], state0, []) + gen_statem:enter_loop(?MODULE, Opts, state0, []) end. undef_code_change(_Config) -> @@ -1642,7 +1661,9 @@ undef_terminate2(_Config) -> undef_in_terminate(_Config) -> Data = {undef_in_terminate, {?MODULE, terminate}}, - {ok, Statem} = gen_statem:start(?MODULE, {data, Data}, []), + {ok, Statem} = + gen_statem:start( + ?MODULE, {data, Data}, [{debug,[log]}]), try gen_statem:stop(Statem), ct:fail(should_crash) diff --git a/lib/stdlib/test/stdlib_bench_SUITE.erl b/lib/stdlib/test/stdlib_bench_SUITE.erl index b937eeb06a..f409d683f4 100644 --- a/lib/stdlib/test/stdlib_bench_SUITE.erl +++ b/lib/stdlib/test/stdlib_bench_SUITE.erl @@ -65,9 +65,9 @@ cases(gen_server) -> [simple, simple_timer, simple_mon, simple_timer_mon, generic, generic_timer]; cases(gen_statem) -> - [generic, generic_fsm, generic_fsm_transit, - generic_statem, generic_statem_transit, - generic_statem_complex]. + [generic, generic_log, generic_log100, generic_fsm, generic_fsm_transit, + generic_statem, generic_statem_log, generic_statem_log100, + generic_statem_transit, generic_statem_complex]. init_per_group(gen_server, Config) -> compile_servers(Config), @@ -290,12 +290,24 @@ simple_timer_mon(Config) when is_list(Config) -> generic(Config) when is_list(Config) -> comment(do_tests(generic, single_small, Config)). +generic_log(Config) when is_list(Config) -> + comment(do_tests(generic_log, single_small, Config)). + +generic_log100(Config) when is_list(Config) -> + comment(do_tests(generic_log100, single_small, Config)). + generic_timer(Config) when is_list(Config) -> comment(do_tests(generic_timer, single_small, Config)). generic_statem(Config) when is_list(Config) -> comment(do_tests(generic_statem, single_small, Config)). +generic_statem_log(Config) when is_list(Config) -> + comment(do_tests(generic_statem_log, single_small, Config)). + +generic_statem_log100(Config) when is_list(Config) -> + comment(do_tests(generic_statem_log100, single_small, Config)). + generic_statem_transit(Config) when is_list(Config) -> comment(do_tests(generic_statem_transit, single_small, Config)). @@ -367,9 +379,9 @@ norm(T, Ref) -> do_tests(Test, ParamSet, Config) -> BenchmarkSuite = ?config(benchmark_suite, Config), - {Client, ServerMod} = bench(Test), + {Client, ServerMod, ServerArg} = bench(Test), {Parallelism, Message} = bench_params(ParamSet), - Fun = create_clients(Message, ServerMod, Client, Parallelism), + Fun = create_clients(Message, ServerMod, ServerArg, Client, Parallelism), {TotalLoops, AllPidTime} = run_test(Fun), try ?CALLS_PER_LOOP * round((1000 * TotalLoops) / AllPidTime) of PerSecond -> @@ -484,27 +496,35 @@ generic_fsm_transit_client(N, M, P) -> generic_fsm_transit_client(N+1, M, P). bench(simple) -> - {fun simple_client/3, simple_server}; + {fun simple_client/3, simple_server, term}; bench(simple_timer) -> - {fun simple_client_timer/3, simple_server_timer}; + {fun simple_client_timer/3, simple_server_timer, term}; bench(simple_mon) -> - {fun simple_client_mon/3, simple_server_mon}; + {fun simple_client_mon/3, simple_server_mon, term}; bench(simple_timer_mon) -> - {fun simple_client_timer_mon/3, simple_server_timer_mon}; + {fun simple_client_timer_mon/3, simple_server_timer_mon, term}; bench(generic) -> - {fun generic_client/3, generic_server}; + {fun generic_client/3, generic_server, [term]}; +bench(generic_log) -> + {fun generic_client/3, generic_server, [term,{debug,[log]}]}; +bench(generic_log100) -> + {fun generic_client/3, generic_server, [term,{debug,[{log,100}]}]}; bench(generic_timer) -> - {fun generic_timer_client/3, generic_server_timer}; + {fun generic_timer_client/3, generic_server_timer, term}; bench(generic_statem) -> - {fun generic_statem_client/3, generic_statem}; + {fun generic_statem_client/3, generic_statem, [term]}; +bench(generic_statem_log) -> + {fun generic_statem_client/3, generic_statem, [term,{debug,[log]}]}; +bench(generic_statem_log100) -> + {fun generic_statem_client/3, generic_statem, [term,{debug,[{log,100}]}]}; bench(generic_statem_transit) -> - {fun generic_statem_transit_client/3, generic_statem}; + {fun generic_statem_transit_client/3, generic_statem, [term]}; bench(generic_statem_complex) -> - {fun generic_statem_complex_client/3, generic_statem_complex}; + {fun generic_statem_complex_client/3, generic_statem_complex, term}; bench(generic_fsm) -> - {fun generic_fsm_client/3, generic_fsm}; + {fun generic_fsm_client/3, generic_fsm, term}; bench(generic_fsm_transit) -> - {fun generic_fsm_transit_client/3, generic_fsm}. + {fun generic_fsm_transit_client/3, generic_fsm, term}. %% -> {Parallelism, MessageTerm} bench_params(single_small) -> {1, small()}; @@ -532,10 +552,9 @@ parallelism() -> _ -> 1 end. -create_clients(M, ServerMod, Client, Parallel) -> +create_clients(M, ServerMod, ServerArg, Client, Parallel) -> fun() -> - State = term, - ServerPid = ServerMod:start(State), + ServerPid = ServerMod:start(ServerArg), PidRefs = [spawn_monitor(fun() -> Client(0, M, ServerPid) end) || _ <- lists:seq(1, Parallel)], timer:sleep(?MAX_TIME), diff --git a/lib/stdlib/test/stdlib_bench_SUITE_data/generic_server.erl b/lib/stdlib/test/stdlib_bench_SUITE_data/generic_server.erl index abd61dcdef..3707d00dee 100644 --- a/lib/stdlib/test/stdlib_bench_SUITE_data/generic_server.erl +++ b/lib/stdlib/test/stdlib_bench_SUITE_data/generic_server.erl @@ -8,8 +8,8 @@ -define(GEN_SERVER, gen_server). -start(State) -> - {ok, Pid} = ?GEN_SERVER:start(?MODULE, State, []), +start([State|Opts]) -> + {ok, Pid} = ?GEN_SERVER:start(?MODULE, State, Opts), Pid. init(State) -> diff --git a/lib/stdlib/test/stdlib_bench_SUITE_data/generic_statem.erl b/lib/stdlib/test/stdlib_bench_SUITE_data/generic_statem.erl index 2e0491f060..cfeb974abd 100644 --- a/lib/stdlib/test/stdlib_bench_SUITE_data/generic_statem.erl +++ b/lib/stdlib/test/stdlib_bench_SUITE_data/generic_statem.erl @@ -28,8 +28,8 @@ %% API -start(Data) -> - {ok, Pid} = gen_statem:start(?MODULE, Data, []), +start([Data|Opts]) -> + {ok, Pid} = gen_statem:start(?MODULE, Data, Opts), Pid. stop(P) -> -- cgit v1.2.3 From 5d530cdfa1f6d7a75f8933b8ce95df8fdbb82b9e Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Thu, 25 Oct 2018 14:15:27 +0200 Subject: Add client stacktrace --- lib/stdlib/src/gen_fsm.erl | 104 +++++++++++++++++++++++++------------- lib/stdlib/src/gen_statem.erl | 51 ++++++++++++++++--- lib/stdlib/test/gen_fsm_SUITE.erl | 12 +++-- 3 files changed, 123 insertions(+), 44 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_fsm.erl b/lib/stdlib/src/gen_fsm.erl index 2e6721e2a1..1b8401305a 100644 --- a/lib/stdlib/src/gen_fsm.erl +++ b/lib/stdlib/src/gen_fsm.erl @@ -411,7 +411,8 @@ decode_msg(Msg,Parent, Name, StateName, StateData, Mod, Time, HibernateAfterTime sys:handle_system_msg(Req, From, Parent, ?MODULE, Debug, [Name, StateName, StateData, Mod, Time, HibernateAfterTimeout], Hib); {'EXIT', Parent, Reason} -> - terminate(Reason, Name, Msg, Mod, StateName, StateData, Debug); + terminate( + Reason, Name, undefined, Msg, Mod, StateName, StateData, Debug); _Msg when Debug =:= [] -> handle_msg(Msg, Parent, Name, StateName, StateData, Mod, Time, HibernateAfterTimeout); _Msg -> @@ -431,7 +432,7 @@ system_continue(Parent, Debug, [Name, StateName, StateData, Mod, Time, Hibernate system_terminate(Reason, _Parent, Debug, [Name, StateName, StateData, Mod, _Time, _HibernateAfterTimeout]) -> - terminate(Reason, Name, [], Mod, StateName, StateData, Debug). + terminate(Reason, Name, undefined, [], Mod, StateName, StateData, Debug). system_code_change([Name, StateName, StateData, Mod, Time, HibernateAfterTimeout], _Module, OldVsn, Extra) -> @@ -495,9 +496,9 @@ handle_msg(Msg, Parent, Name, StateName, StateData, Mod, _Time, HibernateAfterTi reply(From, Reply), loop(Parent, Name, NStateName, NStateData, Mod, Time1, HibernateAfterTimeout, []); {stop, Reason, NStateData} -> - terminate(Reason, Name, Msg, Mod, StateName, NStateData, []); + terminate(Reason, Name, From, Msg, Mod, StateName, NStateData, []); {stop, Reason, Reply, NStateData} when From =/= undefined -> - {'EXIT', R} = (catch terminate(Reason, Name, Msg, Mod, + {'EXIT', R} = (catch terminate(Reason, Name, From, Msg, Mod, StateName, NStateData, [])), reply(From, Reply), exit(R); @@ -510,10 +511,10 @@ handle_msg(Msg, Parent, Name, StateName, StateData, Mod, _Time, HibernateAfterTi error_logger=>#{tag=>warning_msg}}), loop(Parent, Name, StateName, StateData, Mod, infinity, HibernateAfterTimeout, []); {'EXIT', What} -> - terminate(What, Name, Msg, Mod, StateName, StateData, []); + terminate(What, Name, From, Msg, Mod, StateName, StateData, []); Reply -> terminate({bad_return_value, Reply}, - Name, Msg, Mod, StateName, StateData, []) + Name, From, Msg, Mod, StateName, StateData, []) end. handle_msg(Msg, Parent, Name, StateName, StateData, Mod, _Time, HibernateAfterTimeout, Debug) -> @@ -534,17 +535,18 @@ handle_msg(Msg, Parent, Name, StateName, StateData, Mod, _Time, HibernateAfterTi Debug1 = reply(Name, From, Reply, Debug, NStateName), loop(Parent, Name, NStateName, NStateData, Mod, Time1, HibernateAfterTimeout, Debug1); {stop, Reason, NStateData} -> - terminate(Reason, Name, Msg, Mod, StateName, NStateData, Debug); + terminate( + Reason, Name, From, Msg, Mod, StateName, NStateData, Debug); {stop, Reason, Reply, NStateData} when From =/= undefined -> - {'EXIT', R} = (catch terminate(Reason, Name, Msg, Mod, + {'EXIT', R} = (catch terminate(Reason, Name, From, Msg, Mod, StateName, NStateData, Debug)), _ = reply(Name, From, Reply, Debug, StateName), exit(R); {'EXIT', What} -> - terminate(What, Name, Msg, Mod, StateName, StateData, Debug); + terminate(What, Name, From, Msg, Mod, StateName, StateData, Debug); Reply -> terminate({bad_return_value, Reply}, - Name, Msg, Mod, StateName, StateData, Debug) + Name, From, Msg, Mod, StateName, StateData, Debug) end. dispatch({'$gen_event', Event}, Mod, StateName, StateData) -> @@ -580,15 +582,16 @@ reply(Name, {To, Tag}, Reply, Debug, StateName) -> %%% Terminate the server. %%% --------------------------------------------------- --spec terminate(term(), _, _, atom(), _, _, _) -> no_return(). +-spec terminate(term(), _, _, _, atom(), _, _, _) -> no_return(). -terminate(Reason, Name, Msg, Mod, StateName, StateData, Debug) -> +terminate(Reason, Name, From, Msg, Mod, StateName, StateData, Debug) -> case erlang:function_exported(Mod, terminate, 3) of true -> case catch Mod:terminate(Reason, StateName, StateData) of {'EXIT', R} -> FmtStateData = format_status(terminate, Mod, get(), StateData), - error_info(R, Name, Msg, StateName, FmtStateData, Debug), + error_info( + R, Name, From, Msg, StateName, FmtStateData, Debug), exit(R); _ -> ok @@ -605,11 +608,12 @@ terminate(Reason, Name, Msg, Mod, StateName, StateData, Debug) -> exit(Shutdown); _ -> FmtStateData1 = format_status(terminate, Mod, get(), StateData), - error_info(Reason,Name,Msg,StateName,FmtStateData1,Debug), + error_info( + Reason, Name, From, Msg, StateName, FmtStateData1, Debug), exit(Reason) end. -error_info(Reason, Name, Msg, StateName, StateData, Debug) -> +error_info(Reason, Name, From, Msg, StateName, StateData, Debug) -> Log = [{Event, State} || {Event, State, _FormFunc} <- sys:get_log(Debug)], ?LOG_ERROR(#{label=>{gen_fsm,terminate}, name=>Name, @@ -617,19 +621,38 @@ error_info(Reason, Name, Msg, StateName, StateData, Debug) -> state_name=>StateName, state_data=>StateData, log=>Log, - reason=>Reason}, + reason=>Reason, + client_info=>client_stacktrace(From)}, #{domain=>[otp], report_cb=>fun gen_fsm:format_log/1, error_logger=>#{tag=>error}}), ok. +client_stacktrace(undefined) -> + undefined; +client_stacktrace({Pid,_Tag}) -> + client_stacktrace(Pid); +client_stacktrace(Pid) when is_pid(Pid), node(Pid) =:= node() -> + case process_info(Pid, [current_stacktrace, registered_name]) of + undefined -> + {Pid,dead}; + [{current_stacktrace, Stacktrace}, {registered_name, []}] -> + {Pid,{Pid,Stacktrace}}; + [{current_stacktrace, Stacktrace}, {registered_name, Name}] -> + {Pid,{Name,Stacktrace}} + end; +client_stacktrace(Pid) when is_pid(Pid) -> + {Pid,remote}. + + format_log(#{label:={gen_fsm,terminate}, name:=Name, last_message:=Msg, state_name:=StateName, state_data:=StateData, log:=Log, - reason:=Reason}) -> + reason:=Reason, + client_info:=ClientInfo}) -> Reason1 = case Reason of {undef,[{M,F,A,L}|MFAs]} -> @@ -647,6 +670,7 @@ format_log(#{label:={gen_fsm,terminate}, _ -> Reason end, + {ClientFmt,ClientArgs} = format_client_log(ClientInfo), LimitedLog = [error_logger:limit_term(D) || D <- Log], {"** State machine ~tp terminating \n" ++ get_msg_str(Msg) ++ @@ -656,12 +680,13 @@ format_log(#{label:={gen_fsm,terminate}, case LimitedLog of [] -> []; _ -> "** Log ==~n** ~tp~n" - end, - [Name, get_msg(Msg), StateName, StateData, Reason1 | - case LimitedLog of - [] -> []; - _ -> [LimitedLog] - end]}; + end ++ ClientFmt, + [Name|get_msg(Msg)] ++ + [StateName, StateData, Reason1 | + case LimitedLog of + [] -> []; + _ -> [LimitedLog] + end] ++ ClientArgs}; format_log(#{label:={gen_fsm,no_handle_info}, module:=Mod, message:=Msg}) -> @@ -671,12 +696,12 @@ format_log(#{label:={gen_fsm,no_handle_info}, get_msg_str({'$gen_event', _Event}) -> "** Last event in was ~tp~n"; -get_msg_str({'$gen_sync_event', _Event}) -> - "** Last sync event in was ~tp~n"; +get_msg_str({'$gen_sync_event', _From, _Event}) -> + "** Last sync event in was ~tp from ~p~n"; get_msg_str({'$gen_all_state_event', _Event}) -> "** Last event in was ~tp (for all states)~n"; -get_msg_str({'$gen_sync_all_state_event', _Event}) -> - "** Last sync event in was ~tp (for all states)~n"; +get_msg_str({'$gen_sync_all_state_event', _From, _Event}) -> + "** Last sync event in was ~tp (for all states) from ~p~n"; get_msg_str({timeout, _Ref, {'$gen_timer', _Msg}}) -> "** Last timer event in was ~tp~n"; get_msg_str({timeout, _Ref, {'$gen_event', _Msg}}) -> @@ -684,13 +709,24 @@ get_msg_str({timeout, _Ref, {'$gen_event', _Msg}}) -> get_msg_str(_Msg) -> "** Last message in was ~tp~n". -get_msg({'$gen_event', Event}) -> Event; -get_msg({'$gen_sync_event', Event}) -> Event; -get_msg({'$gen_all_state_event', Event}) -> Event; -get_msg({'$gen_sync_all_state_event', Event}) -> Event; -get_msg({timeout, Ref, {'$gen_timer', Msg}}) -> {timeout, Ref, Msg}; -get_msg({timeout, _Ref, {'$gen_event', Event}}) -> Event; -get_msg(Msg) -> Msg. +get_msg({'$gen_event', Event}) -> [Event]; +get_msg({'$gen_sync_event', From, Event}) -> [Event,From]; +get_msg({'$gen_all_state_event', Event}) -> [Event]; +get_msg({'$gen_sync_all_state_event', From, Event}) -> [Event,From]; +get_msg({timeout, Ref, {'$gen_timer', Msg}}) -> [{timeout, Ref, Msg}]; +get_msg({timeout, _Ref, {'$gen_event', Event}}) -> [Event]; +get_msg(Msg) -> [Msg]. + +format_client_log(undefined) -> + {"", []}; +format_client_log({From,dead}) -> + {"** Client ~p is dead~n", [From]}; +format_client_log({From,remote}) -> + {"** Client ~p is remote on node ~p~n", [From, node(From)]}; +format_client_log({_From,{Name,Stacktrace}}) -> + {"** Client ~tp stacktrace~n" + "** ~tp~n", + [Name, Stacktrace]}. %%----------------------------------------------------------------- %% Status information diff --git a/lib/stdlib/src/gen_statem.erl b/lib/stdlib/src/gen_statem.erl index 016665ef35..aef242bd4b 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -1937,11 +1937,36 @@ error_info( state_enter=>StateEnter, state=>format_status(terminate, get(), S), log=>Log, - reason=>{Class,Reason,Stacktrace}}, + reason=>{Class,Reason,Stacktrace}, + client_info=>client_stacktrace(Q)}, #{domain=>[otp], report_cb=>fun gen_statem:format_log/1, error_logger=>#{tag=>error}}). +client_stacktrace([]) -> + undefined; +client_stacktrace([{{call,{Pid,_Tag}},_Req}|_]) when is_pid(Pid) -> + if + node(Pid) =:= node() -> + case + process_info(Pid, [current_stacktrace, registered_name]) + of + undefined -> + {Pid,dead}; + [{current_stacktrace, Stacktrace}, + {registered_name, []}] -> + {Pid,{Pid,Stacktrace}}; + [{current_stacktrace, Stacktrace}, + {registered_name, Name}] -> + {Pid,{Name,Stacktrace}} + end; + true -> + {Pid,remote} + end; +client_stacktrace([_|_]) -> + undefined. + + format_log(#{label:={gen_statem,terminate}, name:=Name, queue:=Q, @@ -1950,7 +1975,8 @@ format_log(#{label:={gen_statem,terminate}, state_enter:=StateEnter, state:=FmtData, log:=Log, - reason:={Class,Reason,Stacktrace}}) -> + reason:={Class,Reason,Stacktrace}, + client_info:=ClientInfo}) -> {FixedReason,FixedStacktrace} = case Stacktrace of [{M,F,Args,_}|ST] @@ -1976,8 +2002,9 @@ format_log(#{label:={gen_statem,terminate}, end; _ -> {Reason,Stacktrace} end, - [LimitedP, LimitedFmtData, LimitedFixedReason | LimitedLog] = - [error_logger:limit_term(D) || D <- [P, FmtData, FixedReason | Log]], + {ClientFmt,ClientArgs} = format_client_log(ClientInfo), + [LimitedP,LimitedFmtData,LimitedFixedReason|LimitedLog] = + [error_logger:limit_term(D) || D <- [P,FmtData,FixedReason|Log]], CBMode = case StateEnter of true -> @@ -2008,7 +2035,7 @@ format_log(#{label:={gen_statem,terminate}, case LimitedLog of [] -> ""; _ -> "** Log =~n** ~tp~n" - end, + end ++ ClientFmt, [Name | case Q of [] -> []; @@ -2032,7 +2059,19 @@ format_log(#{label:={gen_statem,terminate}, case LimitedLog of [] -> []; _ -> [LimitedLog] - end}. + end ++ ClientArgs}. + +format_client_log(undefined) -> + {"", []}; +format_client_log({Pid,dead}) -> + {"** Client ~p is dead~n", [Pid]}; +format_client_log({Pid,remote}) -> + {"** Client ~p is remote on node ~p~n", [Pid, node(Pid)]}; +format_client_log({_Pid,{Name,Stacktrace}}) -> + {"** Client ~tp stacktrace~n" + "** ~tp~n", + [Name, Stacktrace]}. + %% Call Module:format_status/2 or return a default value format_status( diff --git a/lib/stdlib/test/gen_fsm_SUITE.erl b/lib/stdlib/test/gen_fsm_SUITE.erl index 41ee3246f5..4c463ff0d2 100644 --- a/lib/stdlib/test/gen_fsm_SUITE.erl +++ b/lib/stdlib/test/gen_fsm_SUITE.erl @@ -519,14 +519,16 @@ error_format_status(Config) when is_list(Config) -> error_logger_forwarder:register(), OldFl = process_flag(trap_exit, true), StateData = "called format_status", + Parent = self(), {ok, Pid} = gen_fsm:start(gen_fsm_SUITE, {state_data, StateData}, []), %% bad return value in the gen_fsm loop {'EXIT',{{bad_return_value, badreturn},_}} = (catch gen_fsm:sync_send_event(Pid, badreturn)), receive {error,_GroupLeader,{Pid, - "** State machine"++_, - [Pid,{_,_,badreturn},idle,{formatted,StateData},_]}} -> + "** State machine "++_, + [Pid,badreturn,{Parent,_},idle,{formatted,StateData}, + {bad_return_value,badreturn}|_]}} -> ok; Other -> io:format("Unexpected: ~p", [Other]), @@ -539,12 +541,14 @@ terminate_crash_format(Config) when is_list(Config) -> error_logger_forwarder:register(), OldFl = process_flag(trap_exit, true), StateData = crash_terminate, + Parent = self(), {ok, Pid} = gen_fsm:start(gen_fsm_SUITE, {state_data, StateData}, []), stop_it(Pid), receive {error,_GroupLeader,{Pid, - "** State machine"++_, - [Pid,{_,_,_},idle,{formatted, StateData},_]}} -> + "** State machine "++_, + [Pid,stop,{Parent,_},idle,{formatted, StateData}, + {crash,terminate}|_]}} -> ok; Other -> io:format("Unexpected: ~p", [Other]), -- cgit v1.2.3 From 6c17eb4036eaa9afba86929821b6ec81a91c2787 Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Thu, 25 Oct 2018 14:56:36 +0200 Subject: Limit more error_logger terms --- lib/stdlib/src/gen_fsm.erl | 17 +++++++++-------- lib/stdlib/src/gen_server.erl | 12 ++++++------ lib/stdlib/src/gen_statem.erl | 25 +++++++++++-------------- 3 files changed, 26 insertions(+), 28 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_fsm.erl b/lib/stdlib/src/gen_fsm.erl index 1b8401305a..6be12437bb 100644 --- a/lib/stdlib/src/gen_fsm.erl +++ b/lib/stdlib/src/gen_fsm.erl @@ -671,28 +671,29 @@ format_log(#{label:={gen_fsm,terminate}, Reason end, {ClientFmt,ClientArgs} = format_client_log(ClientInfo), - 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" ++ - case LimitedLog of + case Log of [] -> []; _ -> "** Log ==~n** ~tp~n" end ++ ClientFmt, - [Name|get_msg(Msg)] ++ - [StateName, StateData, Reason1 | - case LimitedLog of + [Name|error_logger:limit_term(get_msg(Msg))] ++ + [StateName, + error_logger:limit_term(StateData), + error_logger:limit_term(Reason1) | + case Log of [] -> []; - _ -> [LimitedLog] + _ -> [[error_logger:limit_term(D) || D <- Log]] end] ++ ClientArgs}; format_log(#{label:={gen_fsm,no_handle_info}, module:=Mod, message:=Msg}) -> {"** Undefined handle_info in ~p~n" "** Unhandled message: ~tp~n", - [Mod, Msg]}. + [Mod, error_logger:limit_term(Msg)]}. get_msg_str({'$gen_event', _Event}) -> "** Last event in was ~tp~n"; @@ -726,7 +727,7 @@ format_client_log({From,remote}) -> format_client_log({_From,{Name,Stacktrace}}) -> {"** Client ~tp stacktrace~n" "** ~tp~n", - [Name, Stacktrace]}. + [Name, error_logger:limit_term(Stacktrace)]}. %%----------------------------------------------------------------- %% Status information diff --git a/lib/stdlib/src/gen_server.erl b/lib/stdlib/src/gen_server.erl index 7de62eaf01..3f7c392c12 100644 --- a/lib/stdlib/src/gen_server.erl +++ b/lib/stdlib/src/gen_server.erl @@ -936,11 +936,11 @@ format_log(#{label:={gen_server,terminate}, end end; _ -> - error_logger:limit_term(Reason) + Reason end, {ClientFmt,ClientArgs} = format_client_log(Client), - [LimitedState|LimitedLog] = - [error_logger:limit_term(D) || D <- [State|Log]], + [LimitedMsg,LimitedState,LimitedReason|LimitedLog] = + [error_logger:limit_term(D) || D <- [Msg,State,Reason1|Log]], {"** Generic server ~tp terminating \n" "** Last message in was ~tp~n" "** When Server state == ~tp~n" @@ -949,7 +949,7 @@ format_log(#{label:={gen_server,terminate}, [] -> []; _ -> "** Log ==~n** ~tp~n" end ++ ClientFmt, - [Name, Msg, LimitedState, Reason1] ++ + [Name, LimitedMsg, LimitedState, LimitedReason] ++ case LimitedLog of [] -> []; _ -> [LimitedLog] @@ -959,7 +959,7 @@ format_log(#{label:={gen_server,no_handle_info}, message:=Msg}) -> {"** Undefined handle_info in ~p~n" "** Unhandled message: ~tp~n", - [Mod, Msg]}. + [Mod, error_logger:limit_term(Msg)]}. format_client_log(undefined) -> {"", []}; @@ -970,7 +970,7 @@ format_client_log({From,remote}) -> format_client_log({_From,{Name,Stacktrace}}) -> {"** Client ~tp stacktrace~n" "** ~tp~n", - [Name, Stacktrace]}. + [Name, error_logger:limit_term(Stacktrace)]}. %%----------------------------------------------------------------- %% Status information diff --git a/lib/stdlib/src/gen_statem.erl b/lib/stdlib/src/gen_statem.erl index aef242bd4b..e21a0ecc26 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -1996,15 +1996,12 @@ format_log(#{label:={gen_statem,terminate}, true -> {Reason,Stacktrace}; false -> - {{'function not exported',{M,F,Arity}}, - ST} + {{'function not exported',{M,F,Arity}},ST} end end; _ -> {Reason,Stacktrace} end, {ClientFmt,ClientArgs} = format_client_log(ClientInfo), - [LimitedP,LimitedFmtData,LimitedFixedReason|LimitedLog] = - [error_logger:limit_term(D) || D <- [P,FmtData,FixedReason|Log]], CBMode = case StateEnter of true -> @@ -2032,33 +2029,33 @@ format_log(#{label:={gen_statem,terminate}, [] -> ""; _ -> "** Stacktrace =~n** ~tp~n" end ++ - case LimitedLog of + case Log of [] -> ""; _ -> "** Log =~n** ~tp~n" end ++ ClientFmt, [Name | case Q of [] -> []; - [Event|_] -> [Event] + [Event|_] -> [error_logger:limit_term(Event)] end] ++ - [LimitedFmtData, - Class,LimitedFixedReason, + [error_logger:limit_term(FmtData), + Class,error_logger:limit_term(FixedReason), CBMode] ++ case Q of - [_|[_|_] = Events] -> [Events]; + [_|[_|_] = Events] -> [error_logger:limit_term(Events)]; _ -> [] end ++ case P of [] -> []; - _ -> [LimitedP] + _ -> [error_logger:limit_term(P)] end ++ case FixedStacktrace of [] -> []; - _ -> [FixedStacktrace] + _ -> [error_logger:limit_term(FixedStacktrace)] end ++ - case LimitedLog of + case Log of [] -> []; - _ -> [LimitedLog] + _ -> [[error_logger:limit_term(T) || T <- Log]] end ++ ClientArgs}. format_client_log(undefined) -> @@ -2070,7 +2067,7 @@ format_client_log({Pid,remote}) -> format_client_log({_Pid,{Name,Stacktrace}}) -> {"** Client ~tp stacktrace~n" "** ~tp~n", - [Name, Stacktrace]}. + [Name, error_logger:limit_term(Stacktrace)]}. %% Call Module:format_status/2 or return a default value -- cgit v1.2.3 From 68b9eb83e14304360f83f9a53b128e324a261757 Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Fri, 26 Oct 2018 12:29:18 +0200 Subject: Use from/1 type check --- lib/stdlib/src/gen_statem.erl | 30 ++++++++++++++++++------------ 1 file changed, 18 insertions(+), 12 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_statem.erl b/lib/stdlib/src/gen_statem.erl index e21a0ecc26..854a793a50 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -1861,18 +1861,24 @@ do_reply_then_terminate( do_reply_then_terminate( Class, Reason, Stacktrace, Debug, S, Q, [R|Rs]) -> case R of - {reply,{_To,_Tag}=From,Reply} -> - reply(From, Reply), - NewDebug = - ?sys_debug( - Debug, - begin - #state{name = Name, state = State} = S, - {Name,State} - end, - {out,Reply,From}), - do_reply_then_terminate( - Class, Reason, Stacktrace, NewDebug, S, Q, Rs); + {reply,From,Reply} -> + case from(From) of + true -> + reply(From, Reply), + NewDebug = + ?sys_debug( + Debug, + {S#state.name,S#state.state}, + {out,Reply,From}), + do_reply_then_terminate( + Class, Reason, Stacktrace, NewDebug, S, Q, Rs); + false -> + terminate( + error, + {bad_reply_action_from_state_function,R}, + ?STACKTRACE(), + Debug, S, Q) + end; _ -> terminate( error, -- cgit v1.2.3 From b29db1fd14adcdf067948ceed9e16c520b9b606d Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Fri, 26 Oct 2018 14:33:37 +0200 Subject: Log code change --- lib/stdlib/src/gen_statem.erl | 63 ++++++++++++++++++++++++++----------------- 1 file changed, 39 insertions(+), 24 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_statem.erl b/lib/stdlib/src/gen_statem.erl index 854a793a50..82f875d6a9 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -827,29 +827,37 @@ format_status( sys_debug(Debug, NameState, Entry) -> sys:handle_debug(Debug, fun print_event/3, NameState, Entry). -print_event(Dev, {in,Event}, {Name,State}) -> - io:format( - Dev, "*DBG* ~tp receive ~ts in state ~tp~n", - [Name,event_string(Event),State]); -print_event(Dev, {out,Reply,{To,_Tag}}, {Name,State}) -> - io:format( - Dev, "*DBG* ~tp send ~tp to ~p from state ~tp~n", - [Name,Reply,To,State]); -print_event(Dev, {terminate,Reason}, {Name,State}) -> - io:format( - Dev, "*DBG* ~tp terminate ~tp in state ~tp~n", - [Name,Reason,State]); -print_event(Dev, {Tag,Event,NextState}, {Name,State}) -> - StateString = - case NextState of - State -> - io_lib:format("~tp", [State]); - _ -> - io_lib:format("~tp => ~tp", [State,NextState]) - end, - io:format( - Dev, "*DBG* ~tp ~tw ~ts in state ~ts~n", - [Name,Tag,event_string(Event),StateString]). +print_event(Dev, SystemEvent, {Name,State}) -> + case SystemEvent of + {in,Event} -> + io:format( + Dev, "*DBG* ~tp receive ~ts in state ~tp~n", + [Name,event_string(Event),State]); + {in,Event,code_change} -> + io:format( + Dev, "*DBG* ~tp receive ~ts after code change in state ~tp~n", + [Name,event_string(Event),State]); + {out,Reply,{To,_Tag}} -> + io:format( + Dev, "*DBG* ~tp send ~tp to ~p in state ~tp~n", + [Name,Reply,To,State]); + {terminate,Reason} -> + io:format( + Dev, "*DBG* ~tp terminate ~tp in state ~tp~n", + [Name,Reason,State]); + {Tag,Event,NextState} + when Tag =:= enter; Tag =:= postpone; Tag =:= consume -> + StateString = + case NextState of + State -> + io_lib:format("~tp", [State]); + _ -> + io_lib:format("~tp => ~tp", [State,NextState]) + end, + io:format( + Dev, "*DBG* ~tp ~tw ~ts in state ~ts~n", + [Name,Tag,event_string(Event),StateString]) + end. event_string(Event) -> case Event of @@ -996,7 +1004,14 @@ loop_receive_result(Parent, ?not_sys_debug, S, Type, Content) -> loop_event(Parent, ?not_sys_debug, S, Events, Type, Content); loop_receive_result( Parent, Debug, #state{name = Name, state = State} = S, Type, Content) -> - NewDebug = sys_debug(Debug, {Name,State}, {in,{Type,Content}}), + NewDebug = + case S#state.callback_mode of + undefined -> + sys_debug( + Debug, {Name,State}, {in,{Type,Content},code_change}); + _ -> + sys_debug(Debug, {Name,State}, {in,{Type,Content}}) + end, %% Here is the queue of not yet handled events created Events = [], loop_event(Parent, NewDebug, S, Events, Type, Content). -- cgit v1.2.3 From 65983ac6b21886010b9cab47ab905fd783a79f67 Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Wed, 31 Oct 2018 15:50:46 +0100 Subject: Unify system_events in gen_* --- lib/stdlib/src/gen_fsm.erl | 38 ++++++++++++++++++----------- lib/stdlib/src/gen_server.erl | 14 +++++------ lib/stdlib/src/gen_statem.erl | 50 +++++++++++++++++++++------------------ lib/stdlib/test/gen_fsm_SUITE.erl | 4 ++-- 4 files changed, 60 insertions(+), 46 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_fsm.erl b/lib/stdlib/src/gen_fsm.erl index 6be12437bb..49e3f5981e 100644 --- a/lib/stdlib/src/gen_fsm.erl +++ b/lib/stdlib/src/gen_fsm.erl @@ -417,7 +417,7 @@ decode_msg(Msg,Parent, Name, StateName, StateData, Mod, Time, HibernateAfterTime handle_msg(Msg, Parent, Name, StateName, StateData, Mod, Time, HibernateAfterTimeout); _Msg -> Debug1 = sys:handle_debug(Debug, fun print_event/3, - {Name, StateName}, {in, Msg}), + Name, {in, Msg, StateName}), handle_msg(Msg, Parent, Name, StateName, StateData, Mod, Time, HibernateAfterTimeout, Debug1) end. @@ -453,7 +453,7 @@ system_replace_state(StateFun, [Name, StateName, StateData, Mod, Time, Hibernate %% Format debug messages. Print them as the call-back module sees %% them, not as the real erlang messages. Use trace for that. %%----------------------------------------------------------------- -print_event(Dev, {in, Msg}, {Name, StateName}) -> +print_event(Dev, {in, Msg, StateName}, Name) -> case Msg of {'$gen_event', Event} -> io:format(Dev, "*DBG* ~tp got event ~tp in state ~tw~n", @@ -462,6 +462,16 @@ print_event(Dev, {in, Msg}, {Name, StateName}) -> io:format(Dev, "*DBG* ~tp got all_state_event ~tp in state ~tw~n", [Name, Event, StateName]); + {'$gen_sync_event', {From,_Tag}, Event} -> + io:format(Dev, + "*DBG* ~tp got sync_event ~tp " + "from ~tw in state ~tw~n", + [Name, Event, From, StateName]); + {'$gen_sync_all_state_event', {From,_Tag}, Event} -> + io:format(Dev, + "*DBG* ~tp got sync_all_state_event ~tp " + "from ~tw in state ~tw~n", + [Name, Event, From, StateName]); {timeout, Ref, {'$gen_timer', Message}} -> io:format(Dev, "*DBG* ~tp got timer ~tp in state ~tw~n", @@ -474,11 +484,11 @@ print_event(Dev, {in, Msg}, {Name, StateName}) -> io:format(Dev, "*DBG* ~tp got ~tp in state ~tw~n", [Name, Msg, StateName]) end; -print_event(Dev, {out, Msg, To, StateName}, Name) -> +print_event(Dev, {out, Msg, {To,_Tag}, StateName}, Name) -> io:format(Dev, "*DBG* ~tp sent ~tp to ~tw~n" " and switched to state ~tw~n", [Name, Msg, To, StateName]); -print_event(Dev, return, {Name, StateName}) -> +print_event(Dev, {noreply, StateName}, Name) -> io:format(Dev, "*DBG* ~tp switched to state ~tw~n", [Name, StateName]). @@ -522,11 +532,11 @@ handle_msg(Msg, Parent, Name, StateName, StateData, Mod, _Time, HibernateAfterTi case catch dispatch(Msg, Mod, StateName, StateData) of {next_state, NStateName, NStateData} -> Debug1 = sys:handle_debug(Debug, fun print_event/3, - {Name, NStateName}, return), + Name, {noreply, NStateName}), loop(Parent, Name, NStateName, NStateData, Mod, infinity, HibernateAfterTimeout, Debug1); {next_state, NStateName, NStateData, Time1} -> Debug1 = sys:handle_debug(Debug, fun print_event/3, - {Name, NStateName}, return), + Name, {noreply, NStateName}), loop(Parent, Name, NStateName, NStateData, Mod, Time1, HibernateAfterTimeout, Debug1); {reply, Reply, NStateName, NStateData} when From =/= undefined -> Debug1 = reply(Name, From, Reply, Debug, NStateName), @@ -573,10 +583,10 @@ from(_) -> undefined. reply({To, Tag}, Reply) -> catch To ! {Tag, Reply}. -reply(Name, {To, Tag}, Reply, Debug, StateName) -> - reply({To, Tag}, Reply), +reply(Name, From, Reply, Debug, StateName) -> + reply(From, Reply), sys:handle_debug(Debug, fun print_event/3, Name, - {out, Reply, To, StateName}). + {out, Reply, From, StateName}). %%% --------------------------------------------------- %%% Terminate the server. @@ -698,11 +708,11 @@ format_log(#{label:={gen_fsm,no_handle_info}, get_msg_str({'$gen_event', _Event}) -> "** Last event in was ~tp~n"; get_msg_str({'$gen_sync_event', _From, _Event}) -> - "** Last sync event in was ~tp from ~p~n"; + "** Last sync event in was ~tp from ~tw~n"; get_msg_str({'$gen_all_state_event', _Event}) -> "** Last event in was ~tp (for all states)~n"; get_msg_str({'$gen_sync_all_state_event', _From, _Event}) -> - "** Last sync event in was ~tp (for all states) from ~p~n"; + "** Last sync event in was ~tp (for all states) from ~tw~n"; get_msg_str({timeout, _Ref, {'$gen_timer', _Msg}}) -> "** Last timer event in was ~tp~n"; get_msg_str({timeout, _Ref, {'$gen_event', _Msg}}) -> @@ -711,9 +721,9 @@ get_msg_str(_Msg) -> "** Last message in was ~tp~n". get_msg({'$gen_event', Event}) -> [Event]; -get_msg({'$gen_sync_event', From, Event}) -> [Event,From]; +get_msg({'$gen_sync_event', {From,_Tag}, Event}) -> [Event,From]; get_msg({'$gen_all_state_event', Event}) -> [Event]; -get_msg({'$gen_sync_all_state_event', From, Event}) -> [Event,From]; +get_msg({'$gen_sync_all_state_event', {From,_Tag}, Event}) -> [Event,From]; get_msg({timeout, Ref, {'$gen_timer', Msg}}) -> [{timeout, Ref, Msg}]; get_msg({timeout, _Ref, {'$gen_event', Event}}) -> [Event]; get_msg(Msg) -> [Msg]. @@ -737,7 +747,7 @@ format_status(Opt, StatusData) -> StatusData, Header = gen:format_status_header("Status for state machine", Name), - Log = [{Ev, St} || {Ev, St, _FormFunc} <- sys:get_log(Debug)], + Log = [SysEvent || {SysEvent,_,_} <- 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 3f7c392c12..f57c136296 100644 --- a/lib/stdlib/src/gen_server.erl +++ b/lib/stdlib/src/gen_server.erl @@ -773,10 +773,10 @@ handle_common_reply(Reply, Parent, Name, From, Msg, Mod, HibernateAfterTimeout, terminate({bad_return_value, BadReply}, ?STACKTRACE(), Name, From, Msg, Mod, State, Debug) end. -reply(Name, {To, Tag}, Reply, State, Debug) -> - reply({To, Tag}, Reply), +reply(Name, From, Reply, State, Debug) -> + reply(From, Reply), sys:handle_debug(Debug, fun print_event/3, Name, - {out, Reply, To, State} ). + {out, Reply, From, State} ). %%----------------------------------------------------------------- @@ -810,7 +810,7 @@ system_replace_state(StateFun, [Name, State, Mod, Time, HibernateAfterTimeout]) print_event(Dev, {in, Msg}, Name) -> case Msg of {'$gen_call', {From, _Tag}, Call} -> - io:format(Dev, "*DBG* ~tp got call ~tp from ~w~n", + io:format(Dev, "*DBG* ~tp got call ~tp from ~tw~n", [Name, Call, From]); {'$gen_cast', Cast} -> io:format(Dev, "*DBG* ~tp got cast ~tp~n", @@ -818,8 +818,8 @@ print_event(Dev, {in, Msg}, Name) -> _ -> io:format(Dev, "*DBG* ~tp got ~tp~n", [Name, Msg]) end; -print_event(Dev, {out, Msg, To, State}, Name) -> - io:format(Dev, "*DBG* ~tp sent ~tp to ~w, new state ~tp~n", +print_event(Dev, {out, Msg, {To,_Tag}, State}, Name) -> + io:format(Dev, "*DBG* ~tp sent ~tp to ~tw, new state ~tp~n", [Name, Msg, To, State]); print_event(Dev, {noreply, State}, Name) -> io:format(Dev, "*DBG* ~tp new state ~tp~n", [Name, State]); @@ -885,7 +885,7 @@ 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 = [SysEvent || {SysEvent,_,_} <- sys:get_log(Debug)], ?LOG_ERROR(#{label=>{gen_server,terminate}, name=>Name, last_message=>Msg, diff --git a/lib/stdlib/src/gen_statem.erl b/lib/stdlib/src/gen_statem.erl index 82f875d6a9..3eb9ff3aca 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -680,7 +680,7 @@ enter( data = Data, hibernate_after = HibernateAfterTimeout}, CallEnter = true, - NewDebug = ?sys_debug(Debug, {Name,State}, {enter,Event,State}), + NewDebug = ?sys_debug(Debug, Name, {enter,State}), case call_callback_mode(S) of #state{} = NewS -> loop_event_actions_list( @@ -827,26 +827,30 @@ format_status( sys_debug(Debug, NameState, Entry) -> sys:handle_debug(Debug, fun print_event/3, NameState, Entry). -print_event(Dev, SystemEvent, {Name,State}) -> +print_event(Dev, SystemEvent, Name) -> case SystemEvent of - {in,Event} -> + {in,Event,State} -> io:format( Dev, "*DBG* ~tp receive ~ts in state ~tp~n", [Name,event_string(Event),State]); - {in,Event,code_change} -> + {code_change,Event,State} -> io:format( Dev, "*DBG* ~tp receive ~ts after code change in state ~tp~n", [Name,event_string(Event),State]); {out,Reply,{To,_Tag}} -> io:format( - Dev, "*DBG* ~tp send ~tp to ~p in state ~tp~n", - [Name,Reply,To,State]); - {terminate,Reason} -> + Dev, "*DBG* ~tp send ~tp to ~tw~n", + [Name,Reply,To]); + {enter,State} -> + io:format( + Dev, "*DBG* ~tp enter in state ~tp~n", + [Name,State]); + {terminate,Reason,State} -> io:format( Dev, "*DBG* ~tp terminate ~tp in state ~tp~n", [Name,Reason,State]); - {Tag,Event,NextState} - when Tag =:= enter; Tag =:= postpone; Tag =:= consume -> + {Tag,Event,State,NextState} + when Tag =:= postpone; Tag =:= consume -> StateString = case NextState of State -> @@ -862,7 +866,7 @@ print_event(Dev, SystemEvent, {Name,State}) -> event_string(Event) -> case Event of {{call,{Pid,_Tag}},Request} -> - io_lib:format("call ~tp from ~w", [Request,Pid]); + io_lib:format("call ~tp from ~tw", [Request,Pid]); {EventType,EventContent} -> io_lib:format("~tw ~tp", [EventType,EventContent]) end. @@ -1004,13 +1008,13 @@ loop_receive_result(Parent, ?not_sys_debug, S, Type, Content) -> loop_event(Parent, ?not_sys_debug, S, Events, Type, Content); loop_receive_result( Parent, Debug, #state{name = Name, state = State} = S, Type, Content) -> + Event = {Type,Content}, NewDebug = case S#state.callback_mode of undefined -> - sys_debug( - Debug, {Name,State}, {in,{Type,Content},code_change}); + sys_debug(Debug, Name, {code_change,Event,State}); _ -> - sys_debug(Debug, {Name,State}, {in,{Type,Content}}) + sys_debug(Debug, Name, {in,Event,State}) end, %% Here is the queue of not yet handled events created Events = [], @@ -1321,13 +1325,13 @@ parse_actions_reply( ?STACKTRACE(), Debug] end; parse_actions_reply( - StateCall, Debug, #state{name = Name, state = State} = S, + StateCall, Debug, #state{name = Name} = S, Actions, TransOpts, From, Reply) -> %% case from(From) of true -> reply(From, Reply), - NewDebug = sys_debug(Debug, {Name,State}, {out,Reply,From}), + NewDebug = sys_debug(Debug, Name, {out,Reply,From}), parse_actions(StateCall, NewDebug, S, Actions, TransOpts); false -> [error, @@ -1356,7 +1360,7 @@ parse_actions_next_event( Actions, TransOpts, Type, Content) -> case event_type(Type) of true when StateCall -> - NewDebug = sys_debug(Debug, {Name,State}, {in,{Type,Content}}), + NewDebug = sys_debug(Debug, Name, {in,{Type,Content},State}), NextEventsR = TransOpts#trans_opts.next_events_r, parse_actions( StateCall, NewDebug, S, Actions, @@ -1473,14 +1477,14 @@ loop_event_done( true -> [?sys_debug( Debug_0, - {S#state.name,State}, - {postpone,Event_0,NextState}), + S#state.name, + {postpone,Event_0,State,NextState}), Event_0|P_0]; false -> [?sys_debug( Debug_0, - {S#state.name,State}, - {consume,Event_0,NextState})|P_0] + S#state.name, + {consume,Event_0,State,NextState})|P_0] end, {Events_2,P_2, Timers_2} = @@ -1883,7 +1887,7 @@ do_reply_then_terminate( NewDebug = ?sys_debug( Debug, - {S#state.name,S#state.state}, + S#state.name, {out,Reply,From}), do_reply_then_terminate( Class, Reason, Stacktrace, NewDebug, S, Q, Rs); @@ -1938,7 +1942,7 @@ terminate( end. terminate_sys_debug(Debug, S, State, Reason) -> - ?sys_debug(Debug, {S#state.name,State}, {terminate,Reason}). + ?sys_debug(Debug, S#state.name, {terminate,Reason,State}). error_info( @@ -1949,7 +1953,7 @@ error_info( state_enter = StateEnter, postponed = P} = S, Q) -> - Log = [{Ev, St} || {Ev, St, _FormFunc} <- sys:get_log(Debug)], + Log = [SysEvent || {SysEvent,_,_} <- sys:get_log(Debug)], ?LOG_ERROR(#{label=>{gen_statem,terminate}, name=>Name, queue=>Q, diff --git a/lib/stdlib/test/gen_fsm_SUITE.erl b/lib/stdlib/test/gen_fsm_SUITE.erl index 4c463ff0d2..c942695a6a 100644 --- a/lib/stdlib/test/gen_fsm_SUITE.erl +++ b/lib/stdlib/test/gen_fsm_SUITE.erl @@ -527,7 +527,7 @@ error_format_status(Config) when is_list(Config) -> receive {error,_GroupLeader,{Pid, "** State machine "++_, - [Pid,badreturn,{Parent,_},idle,{formatted,StateData}, + [Pid,badreturn,Parent,idle,{formatted,StateData}, {bad_return_value,badreturn}|_]}} -> ok; Other -> @@ -547,7 +547,7 @@ terminate_crash_format(Config) when is_list(Config) -> receive {error,_GroupLeader,{Pid, "** State machine "++_, - [Pid,stop,{Parent,_},idle,{formatted, StateData}, + [Pid,stop,Parent,idle,{formatted, StateData}, {crash,terminate}|_]}} -> ok; Other -> -- cgit v1.2.3 From 8893e9f9d0a25c0b3c8cc78765df5cdc0de0bdf8 Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Wed, 31 Oct 2018 16:40:14 +0100 Subject: Adjust sys:log(N, get) to documentation --- lib/stdlib/src/gen_fsm.erl | 4 ++-- lib/stdlib/src/gen_server.erl | 4 ++-- lib/stdlib/src/gen_statem.erl | 4 ++-- lib/stdlib/src/sys.erl | 4 ++-- 4 files changed, 8 insertions(+), 8 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_fsm.erl b/lib/stdlib/src/gen_fsm.erl index 49e3f5981e..fec7c6a5a3 100644 --- a/lib/stdlib/src/gen_fsm.erl +++ b/lib/stdlib/src/gen_fsm.erl @@ -624,7 +624,7 @@ terminate(Reason, Name, From, Msg, Mod, StateName, StateData, Debug) -> end. error_info(Reason, Name, From, Msg, StateName, StateData, Debug) -> - Log = [{Event, State} || {Event, State, _FormFunc} <- sys:get_log(Debug)], + Log = sys:get_log(Debug), ?LOG_ERROR(#{label=>{gen_fsm,terminate}, name=>Name, last_message=>Msg, @@ -747,7 +747,7 @@ format_status(Opt, StatusData) -> StatusData, Header = gen:format_status_header("Status for state machine", Name), - Log = [SysEvent || {SysEvent,_,_} <- sys:get_log(Debug)], + Log = 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 f57c136296..7a415c7620 100644 --- a/lib/stdlib/src/gen_server.erl +++ b/lib/stdlib/src/gen_server.erl @@ -885,7 +885,7 @@ error_info(_Reason, application_controller, _From, _Msg, _Mod, _State, _Debug) - %% of it instead ok; error_info(Reason, Name, From, Msg, Mod, State, Debug) -> - Log = [SysEvent || {SysEvent,_,_} <- sys:get_log(Debug)], + Log = sys:get_log(Debug), ?LOG_ERROR(#{label=>{gen_server,terminate}, name=>Name, last_message=>Msg, @@ -978,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 = [{Ev, St} || {Ev, St, _FormFunc} <- sys:get_log(Debug)], + Log = 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 3eb9ff3aca..4efe68d7f9 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -807,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 = [{Event, State} || {Event, State, _FormFunc} <- sys:get_log(Debug)], + Log = sys:get_log(Debug), [{header,Header}, {data, [{"Status",SysState}, @@ -1953,7 +1953,7 @@ error_info( state_enter = StateEnter, postponed = P} = S, Q) -> - Log = [SysEvent || {SysEvent,_,_} <- sys:get_log(Debug)], + Log = sys:get_log(Debug), ?LOG_ERROR(#{label=>{gen_statem,terminate}, name=>Name, queue=>Q, diff --git a/lib/stdlib/src/sys.erl b/lib/stdlib/src/sys.erl index 6775dfe933..09fe497d11 100644 --- a/lib/stdlib/src/sys.erl +++ b/lib/stdlib/src/sys.erl @@ -548,7 +548,7 @@ debug_cmd({log, print}, Debug) -> {ok, Debug}; debug_cmd({log, get}, Debug) -> NLog = get_debug(log, Debug, nlog_new()), - {{ok, nlog_get(NLog)}, Debug}; + {{ok, [Event || {Event, _State, _FormFunc} <- nlog_get(NLog)]}, Debug}; debug_cmd({log_to_file, false}, Debug) -> NDebug = close_log_file(Debug), {ok, NDebug}; @@ -639,7 +639,7 @@ print_log(Debug) -> Debug :: [dbg_opt()]. get_log(Debug) -> NLog = get_debug(log, Debug, nlog_new()), - nlog_get(NLog). + [Event || {Event, _State, _FormFunc} <- nlog_get(NLog)]. close_log_file(Debug) -> case get_debug2(log_to_file, Debug, []) of -- cgit v1.2.3 From a447b904cff36fa2d690f1d0068eb28589369787 Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Mon, 5 Nov 2018 16:40:52 +0100 Subject: Document system_events better --- lib/stdlib/doc/src/sys.xml | 166 ++++++++++++++++++++++++++++++++++++++++ lib/stdlib/src/otp_internal.erl | 8 ++ lib/stdlib/src/sys.erl | 12 ++- 3 files changed, 184 insertions(+), 2 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/doc/src/sys.xml b/lib/stdlib/doc/src/sys.xml index 9fe816e33a..78ae4b5c38 100644 --- a/lib/stdlib/doc/src/sys.xml +++ b/lib/stdlib/doc/src/sys.xml @@ -114,6 +114,154 @@ + + + {in,Msg} + +

+ Is produced by gen_server and gen_event + when the message Msg arrives. +

+ + {in,Msg,State} + +

+ Is produced by gen_statem + when the message Msg arrives in state State. +

+

+ For gen_statem the Msg term is + an {EventType,EventContent} tuple. +

+ + {out,Msg,To} + +

+ Is produced by gen_statem when the reply Msg + is sent back to To by returning + a {reply,To,Msg} action from the callback module. +

+

+ To is of the same type + as the first argument to gen_statem:reply/2. +

+ + + {out,Msg,To,State} + + +

+ Is produced by gen_server + when the reply Msg + is sent back to To + by returning a {reply,...} tuple + from the callback module. +

+

+ To is of the same type + as the first argument to gen_server:reply/2. +

+

+ State is the new server state. +

+ + + {noreply,State} + + +

+ Is produced by gen_server + when a {noreply,...} tuple is returned + from the callback module. +

+

+ State is the new server state. +

+ + + {continue,Continuation} + + +

+ Is produced by gen_server + when a {continue,Continuation} + tuple is returned from the callback module. +

+ + + {code_change,Event,State} + + +

+ Is produced by gen_statem + when the message Event + arrives in state State + as the first event after a code change. +

+

+ Event is + an {EventType,EventContent} tuple. +

+ + + + {postpone,Event,State,NextState} + + + +

+ Is produced by gen_statem + when the message Event + is postponed in state State. + NextState is the new state. +

+

+ Event is + an {EventType,EventContent} tuple. +

+ + + + {consume,Event,State,NextState} + + + +

+ Is produced by gen_statem + when the message Event + is consumed in state State. + NextState is the new state. +

+

+ Event is + an {EventType,EventContent} tuple. +

+ + + + {enter,State} + + + +

+ Is produced by gen_statem + when the first state State is entered. +

+ + + + {terminate,Reason,State} + + + +

+ Is produced by gen_statem + when it terminates with reason Reason + in state State. +

+ + + @@ -532,6 +680,12 @@ Get the data associated with a debug option. + +

+ get_debug/3 is deprecated since it returns + data of an internal type only useful for debugging. +

+

Gets the data associated with a debug option. Default is returned if Item is not found. Can be @@ -604,6 +758,18 @@ + + + Return the logged events in the debug structure. + +

+ Returns the logged system events in the debug structure, + that is the last argument to + handle_debug/4. +

+ + + Module:system_code_change(Misc, Module, OldVsn, Extra) -> {ok, NMisc} diff --git a/lib/stdlib/src/otp_internal.erl b/lib/stdlib/src/otp_internal.erl index aaed13ba3a..a0fbd259e2 100644 --- a/lib/stdlib/src/otp_internal.erl +++ b/lib/stdlib/src/otp_internal.erl @@ -55,6 +55,14 @@ obsolete_1(erlang, now, 0) -> obsolete_1(calendar, local_time_to_universal_time, 1) -> {deprecated, {calendar, local_time_to_universal_time_dst, 1}}; +%% *** STDLIB added in OTP 22 *** + +obsolete_1(sys, get_debug, 3) -> + {deprecated, + "Deprecated function. " + "Incorrectly documented and in fact only for internal use. " + "Can often be replaced with sys:get_log/1."}; + %% *** STDLIB added in OTP 20 *** obsolete_1(gen_fsm, start, 3) -> diff --git a/lib/stdlib/src/sys.erl b/lib/stdlib/src/sys.erl index 09fe497d11..11513b3482 100644 --- a/lib/stdlib/src/sys.erl +++ b/lib/stdlib/src/sys.erl @@ -31,6 +31,7 @@ install/2, install/3, remove/2, remove/3]). -export([handle_system_msg/6, handle_system_msg/7, handle_debug/4, print_log/1, get_log/1, get_debug/3, debug_options/1, suspend_loop_hib/6]). +-deprecated([{get_debug,3,eventually}]). %%----------------------------------------------------------------- %% Types @@ -42,10 +43,17 @@ | {'global', term()} | {'via', module(), term()}. -type system_event() :: {'in', Msg :: _} - | {'in', Msg :: _, From :: _} + | {'in', Msg :: _, State :: _} | {'out', Msg :: _, To :: _} | {'out', Msg :: _, To :: _, State :: _} - | term(). + | {'noreply', State :: _} + | {'continue', Continuation :: _} + | {'code_change', Event :: _, State :: _} + | {'postpone', Event :: _, State :: _, NextState :: _} + | {'consume', Event :: _, State :: _, NextState :: _} + | {'enter', State :: _} + | {'terminate', Reason :: _, State :: _} + | term(). -opaque dbg_opt() :: {'trace', 'true'} | {'log', {N :: non_neg_integer(), -- cgit v1.2.3 From f67a1cfcbdb2fbbdd9ff21467d08b61242c2d9cc Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Mon, 5 Nov 2018 17:01:30 +0100 Subject: Fix statement duplication --- lib/stdlib/src/gen_fsm.erl | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_fsm.erl b/lib/stdlib/src/gen_fsm.erl index fec7c6a5a3..1e18710738 100644 --- a/lib/stdlib/src/gen_fsm.erl +++ b/lib/stdlib/src/gen_fsm.erl @@ -748,17 +748,17 @@ format_status(Opt, StatusData) -> Header = gen:format_status_header("Status for state machine", Name), Log = 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; - S -> [S] - end, + Specific = + case format_status(Opt, Mod, PDict, StateData) of + S when is_list(S) -> S; + S -> [S] + end, [{header, Header}, {data, [{"Status", SysState}, {"Parent", Parent}, {"Logged events", Log}, {"StateName", StateName}]} | - Specfic]. + Specific]. format_status(Opt, Mod, PDict, State) -> DefStatus = case Opt of -- cgit v1.2.3 From d35353f9f237cc5cd6e7adf30ca58a2d9e90c90a Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Mon, 5 Nov 2018 17:09:33 +0100 Subject: Filter gen_server State in crash sys:log --- lib/stdlib/src/gen_server.erl | 17 +++++++++++++---- 1 file changed, 13 insertions(+), 4 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_server.erl b/lib/stdlib/src/gen_server.erl index 7a415c7620..c7b6406f54 100644 --- a/lib/stdlib/src/gen_server.erl +++ b/lib/stdlib/src/gen_server.erl @@ -890,7 +890,7 @@ error_info(Reason, Name, From, Msg, Mod, State, Debug) -> name=>Name, last_message=>Msg, state=>format_status(terminate, Mod, get(), State), - log=>Log, + log=>format_log_state(Mod, Log), reason=>Reason, client_info=>client_stacktrace(From)}, #{domain=>[otp], @@ -979,15 +979,24 @@ 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_log(Debug), - Specfic = case format_status(Opt, Mod, PDict, State) of + Specific = case format_status(Opt, Mod, PDict, State) of S when is_list(S) -> S; S -> [S] end, [{header, Header}, {data, [{"Status", SysState}, {"Parent", Parent}, - {"Logged events", Log}]} | - Specfic]. + {"Logged events", format_log_state(Mod, Log)}]} | + Specific]. + +format_log_state(Mod, Log) -> + [case Event of + {out,Msg,From,State} -> + {out,Msg,From,format_status(terminate, Mod, get(), State)}; + {noreply,State} -> + {noreply,format_status(terminate, Mod, get(), State)}; + _ -> Event + end || Event <- Log]. format_status(Opt, Mod, PDict, State) -> DefStatus = case Opt of -- cgit v1.2.3 From 9f2c972e88f8fc8581c9e90b1fcccf9f5c7f1c0f Mon Sep 17 00:00:00 2001 From: Raimo Niskanen Date: Tue, 6 Nov 2018 08:49:39 +0100 Subject: sys:log timeout 0 events --- lib/stdlib/src/gen_statem.erl | 35 +++++++++++++++++++++++------------ 1 file changed, 23 insertions(+), 12 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/gen_statem.erl b/lib/stdlib/src/gen_statem.erl index 4efe68d7f9..6f1f6a0228 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -1509,9 +1509,11 @@ loop_event_done( %% Place next events last in reversed queue Events_3R = lists:reverse(Events_2, NextEventsR), %% Enqueue immediate timeout events - Events_4R = prepend_timeout_events(TimeoutEvents, Events_3R), + [Debug_2|Events_4R] = + prepend_timeout_events( + NextState, Debug_1, S, TimeoutEvents, Events_3R), loop_event_done( - Parent, Debug_1, + Parent, Debug_2, S#state{ state = NextState, data = NewData, @@ -1848,22 +1850,31 @@ parse_timers( %% so if there are enqueued events before the event timer %% timeout 0 event - the event timer is cancelled hence no event. %% -%% Other (state_timeout) timeout 0 events that are after -%% the event timer timeout 0 events are considered to +%% Other (state_timeout and {timeout,Name}) timeout 0 events +%% that are after an event timer timeout 0 event are considered to %% belong to timers that were started after the event timer %% timeout 0 event fired, so they do not cancel the event timer. %% -prepend_timeout_events([], EventsR) -> - EventsR; -prepend_timeout_events([{timeout,_} = TimeoutEvent|TimeoutEvents], []) -> - prepend_timeout_events(TimeoutEvents, [TimeoutEvent]); -prepend_timeout_events([{timeout,_}|TimeoutEvents], EventsR) -> +prepend_timeout_events(_NextState, Debug, _S, [], EventsR) -> + [Debug|EventsR]; +prepend_timeout_events( + NextState, Debug, S, [{timeout,_} = TimeoutEvent|TimeoutEvents], []) -> + prepend_timeout_events( + NextState, + sys_debug(Debug, S#state.name, {in,TimeoutEvent,NextState}), + S, TimeoutEvents, [TimeoutEvent]); +prepend_timeout_events( + NextState, Debug, S, [{timeout,_}|TimeoutEvents], EventsR) -> %% Ignore since there are other events in queue %% so they have cancelled the event timeout 0. - prepend_timeout_events(TimeoutEvents, EventsR); -prepend_timeout_events([TimeoutEvent|TimeoutEvents], EventsR) -> + prepend_timeout_events(NextState, Debug, S, TimeoutEvents, EventsR); +prepend_timeout_events( + NextState, Debug, S, [TimeoutEvent|TimeoutEvents], EventsR) -> %% Just prepend all others - prepend_timeout_events(TimeoutEvents, [TimeoutEvent|EventsR]). + prepend_timeout_events( + NextState, + sys_debug(Debug, S#state.name, {in,TimeoutEvent,NextState}), + S, TimeoutEvents, [TimeoutEvent|EventsR]). -- cgit v1.2.3