diff options
author | Steve Vinoski <[email protected]> | 2010-02-27 23:36:20 -0500 |
---|---|---|
committer | Björn Gustavsson <[email protected]> | 2010-05-12 07:40:26 +0200 |
commit | 5ec0ade4105d5d72f318b657bff1a628881cbf9d (patch) | |
tree | 036de21bae7fe104f9efbe06574f67474c5d90fb /lib/stdlib | |
parent | dd908223cbf62adfeaefac982c4087cd35bb1805 (diff) | |
download | otp-5ec0ade4105d5d72f318b657bff1a628881cbf9d.tar.gz otp-5ec0ade4105d5d72f318b657bff1a628881cbf9d.tar.bz2 otp-5ec0ade4105d5d72f318b657bff1a628881cbf9d.zip |
Extend format_status for gen_server/gen_fsm termination error logging
When a gen_server or gen_fsm process terminates abnormally, sometimes
the text representation of the process state can occupy many lines of
the error log, depending on the definition of the state
term. Developers sometimes would like a way to trim out parts of the
state from the log if those parts don't contribute to documenting the
circumstances of the error, thereby helping to reduce the amount of
logged output.
Since the format_status callback can already format and specialize
gen_server and gen_fsm state for inclusion in the term returned from
sys:get_status, this patch extends format_status in a
backward-compatible way to also be able to specialize the state logged
for abnormal gen_server and gen_fsm termination, and includes new unit
tests to verify the new functionality.
This patch also eliminates the previous restriction that the status
returned by format_status must be a list. It can now be any term.
The documentation is extended to cover the new usage for
format_status, and it's been improved to recommend a form for the
normal case that allows the returned status to fit well with the rest
of the term returned by sys:get_status. The documentation is clear
that this form is only recommended, not required.
Diffstat (limited to 'lib/stdlib')
-rw-r--r-- | lib/stdlib/doc/src/gen_fsm.xml | 58 | ||||
-rw-r--r-- | lib/stdlib/doc/src/gen_server.xml | 55 | ||||
-rw-r--r-- | lib/stdlib/src/gen_fsm.erl | 23 | ||||
-rw-r--r-- | lib/stdlib/src/gen_server.erl | 23 | ||||
-rw-r--r-- | lib/stdlib/test/gen_fsm_SUITE.erl | 31 | ||||
-rw-r--r-- | lib/stdlib/test/gen_server_SUITE.erl | 42 |
6 files changed, 182 insertions, 50 deletions
diff --git a/lib/stdlib/doc/src/gen_fsm.xml b/lib/stdlib/doc/src/gen_fsm.xml index 739cd0bffd..a18d31da17 100644 --- a/lib/stdlib/doc/src/gen_fsm.xml +++ b/lib/stdlib/doc/src/gen_fsm.xml @@ -730,33 +730,58 @@ gen_fsm:sync_send_all_state_event -----> Module:handle_sync_event/4 </desc> </func> <func> - <name>Module:format_status(normal, [PDict, StateData]) -> Status</name> + <name>Module:format_status(Opt, [PDict, StateData]) -> Status</name> <fsummary>Optional function for providing a term describing the current gen_fsm status.</fsummary> <type> + <v>Opt = normal | terminate</v> <v>PDict = [{Key, Value}]</v> <v>StateData = term()</v> - <v>Status = [term()]</v> + <v>Status = term()</v> </type> <desc> - <p><em>This callback is optional, so callback modules need not - export it. The gen_fsm module provides a default - implementation of this function that returns the callback - module state data.</em></p> - <p>This function is called by a gen_fsm process when one - of <seealso marker="sys#get_status/1">sys:get_status/1,2</seealso> - is invoked to get the gen_fsm status. A callback module - wishing to customise the <c>sys:get_status/1,2</c> return - value exports an instance of <c>format_status/2</c> that - returns a term describing the current status of the - gen_fsm.</p> + <note> + <p>This callback is optional, so callback modules need not + export it. The gen_fsm module provides a default + implementation of this function that returns the callback + module state data.</p> + </note> + <p>This function is called by a gen_fsm process when:</p> + <list typed="bulleted"> + <item>One + of <seealso marker="sys#get_status/1">sys:get_status/1,2</seealso> + is invoked to get the gen_fsm status. <c>Opt</c> is set to + the atom <c>normal</c> for this case.</item> + <item>The gen_fsm terminates abnormally and logs an + error. <c>Opt</c> is set to the atom <c>terminate</c> for + this case.</item> + </list> + <p>This function is useful for customising the form and + appearance of the gen_fsm status for these cases. A callback + module wishing to customise the <c>sys:get_status/1,2</c> + return value as well as how its status appears in + termination error logs exports an instance + of <c>format_status/2</c> that returns a term describing the + current status of the gen_fsm.</p> <p><c>PDict</c> is the current value of the gen_fsm's process dictionary.</p> <p><c>StateData</c> is the internal state data of the gen_fsm.</p> - <p>The function should return <c>Status</c>, a list of one or - more terms that customise the details of the current state - and status of the gen_fsm.</p> + <p>The function should return <c>Status</c>, a term that + customises the details of the current state and status of + the gen_fsm. There are no restrictions on the + form <c>Status</c> can take, but for + the <c>sys:get_status/1,2</c> case (when <c>Opt</c> + is <c>normal</c>), the recommended form for + the <c>Status</c> value is <c>[{data, [{"StateData", + Term}]}]</c> where <c>Term</c> provides relevant details of + the gen_fsm state data. Following this recommendation isn't + required, but doing so will make the callback module status + consistent with the rest of the <c>sys:get_status/1,2</c> + return value.</p> + <p>One use for this function is to return compact alternative + state data representations to avoid having large state terms + printed in logfiles.</p> </desc> </func> </funcs> @@ -770,4 +795,3 @@ gen_fsm:sync_send_all_state_event -----> Module:handle_sync_event/4 <seealso marker="sys">sys(3)</seealso></p> </section> </erlref> - diff --git a/lib/stdlib/doc/src/gen_server.xml b/lib/stdlib/doc/src/gen_server.xml index 30c04d1d52..7a4aff4b11 100644 --- a/lib/stdlib/doc/src/gen_server.xml +++ b/lib/stdlib/doc/src/gen_server.xml @@ -599,32 +599,57 @@ gen_server:abcast -----> Module:handle_cast/2 </desc> </func> <func> - <name>Module:format_status(normal, [PDict, State]) -> Status</name> + <name>Module:format_status(Opt, [PDict, State]) -> Status</name> <fsummary>Optional function for providing a term describing the current gen_server status.</fsummary> <type> + <v>Opt = normal | terminate</v> <v>PDict = [{Key, Value}]</v> <v>State = term()</v> - <v>Status = [term()]</v> + <v>Status = term()</v> </type> <desc> - <p><em>This callback is optional, so callback modules need not - export it. The gen_server module provides a default - implementation of this function that returns the callback - module state.</em></p> - <p>This function is called by a gen_server process when one + <note> + <p>This callback is optional, so callback modules need not + export it. The gen_server module provides a default + implementation of this function that returns the callback + module state.</p> + </note> + <p>This function is called by a gen_server process when:</p> + <list typed="bulleted"> + <item>One of <seealso marker="sys#get_status/1">sys:get_status/1,2</seealso> - is invoked to get the gen_server status. A callback module - wishing to customise the <c>sys:get_status/1,2</c> return - value exports an instance of <c>format_status/2</c> that - returns a term describing the current status of the - gen_server.</p> + is invoked to get the gen_server status. <c>Opt</c> is set + to the atom <c>normal</c> for this case.</item> + <item>The gen_server terminates abnormally and logs an + error. <c>Opt</c> is set to the atom <c>terminate</c> for this + case.</item> + </list> + <p>This function is useful for customising the form and + appearance of the gen_server status for these cases. A + callback module wishing to customise + the <c>sys:get_status/1,2</c> return value as well as how + its status appears in termination error logs exports an + instance of <c>format_status/2</c> that returns a term + describing the current status of the gen_server.</p> <p><c>PDict</c> is the current value of the gen_server's process dictionary.</p> <p><c>State</c> is the internal state of the gen_server.</p> - <p>The function should return <c>Status</c>, a list of one or - more terms that customise the details of the current state - and status of the gen_server.</p> + <p>The function should return <c>Status</c>, a term that + customises the details of the current state and status of + the gen_server. There are no restrictions on the + form <c>Status</c> can take, but for + the <c>sys:get_status/1,2</c> case (when <c>Opt</c> + is <c>normal</c>), the recommended form for + the <c>Status</c> value is <c>[{data, [{"State", + Term}]}]</c> where <c>Term</c> provides relevant details of + the gen_server state. Following this recommendation isn't + required, but doing so will make the callback module status + consistent with the rest of the <c>sys:get_status/1,2</c> + return value.</p> + <p>One use for this function is to return compact alternative + state representations to avoid having large state terms + printed in logfiles.</p> </desc> </func> </funcs> diff --git a/lib/stdlib/src/gen_fsm.erl b/lib/stdlib/src/gen_fsm.erl index 9961646418..8d1b46d6ab 100644 --- a/lib/stdlib/src/gen_fsm.erl +++ b/lib/stdlib/src/gen_fsm.erl @@ -542,7 +542,18 @@ terminate(Reason, Name, Msg, Mod, StateName, StateData, Debug) -> {shutdown,_}=Shutdown -> exit(Shutdown); _ -> - error_info(Reason, Name, Msg, StateName, StateData, Debug), + FmtStateData = + case erlang:function_exported(Mod, format_status, 2) of + true -> + Args = [get(), StateData], + case catch Mod:format_status(terminate, Args) of + {'EXIT', _} -> StateData; + Else -> Else + end; + _ -> + StateData + end, + error_info(Reason,Name,Msg,StateName,FmtStateData,Debug), exit(Reason) end end. @@ -610,15 +621,17 @@ format_status(Opt, StatusData) -> end, Header = lists:concat(["Status for state machine ", NameTag]), Log = sys:get_debug(log, Debug, []), - Specfic = + DefaultStatus = [{data, [{"StateData", StateData}]}], + Specfic = case erlang:function_exported(Mod, format_status, 2) of true -> case catch Mod:format_status(Opt,[PDict,StateData]) of - {'EXIT', _} -> [{data, [{"StateData", StateData}]}]; - Else -> Else + {'EXIT', _} -> DefaultStatus; + StatusList when is_list(StatusList) -> StatusList; + Else -> [Else] end; _ -> - [{data, [{"StateData", StateData}]}] + DefaultStatus end, [{header, Header}, {data, [{"Status", SysState}, diff --git a/lib/stdlib/src/gen_server.erl b/lib/stdlib/src/gen_server.erl index 1c9e5270b6..dc8e7ecd16 100644 --- a/lib/stdlib/src/gen_server.erl +++ b/lib/stdlib/src/gen_server.erl @@ -705,7 +705,18 @@ terminate(Reason, Name, Msg, Mod, State, Debug) -> {shutdown,_}=Shutdown -> exit(Shutdown); _ -> - error_info(Reason, Name, Msg, State, Debug), + FmtState = + case erlang:function_exported(Mod, format_status, 2) of + true -> + Args = [get(), State], + case catch Mod:format_status(terminate, Args) of + {'EXIT', _} -> State; + Else -> Else + end; + _ -> + State + end, + error_info(Reason, Name, Msg, FmtState, Debug), exit(Reason) end end. @@ -836,15 +847,17 @@ format_status(Opt, StatusData) -> end, Header = lists:concat(["Status for generic server ", NameTag]), Log = sys:get_debug(log, Debug, []), - Specfic = + DefaultStatus = [{data, [{"State", State}]}], + Specfic = case erlang:function_exported(Mod, format_status, 2) of true -> case catch Mod:format_status(Opt, [PDict, State]) of - {'EXIT', _} -> [{data, [{"State", State}]}]; - Else -> Else + {'EXIT', _} -> DefaultStatus; + StatusList when is_list(StatusList) -> StatusList; + Else -> [Else] end; _ -> - [{data, [{"State", State}]}] + DefaultStatus end, [{header, Header}, {data, [{"Status", SysState}, diff --git a/lib/stdlib/test/gen_fsm_SUITE.erl b/lib/stdlib/test/gen_fsm_SUITE.erl index 23c1d9a193..1f28216375 100644 --- a/lib/stdlib/test/gen_fsm_SUITE.erl +++ b/lib/stdlib/test/gen_fsm_SUITE.erl @@ -30,7 +30,7 @@ -export([shutdown/1]). --export([sys/1, sys1/1, call_format_status/1]). +-export([sys/1, sys1/1, call_format_status/1, error_format_status/1]). -export([hibernate/1,hiber_idle/3,hiber_wakeup/3,hiber_idle/2,hiber_wakeup/2]). @@ -305,7 +305,7 @@ shutdown(Config) when is_list(Config) -> ok. -sys(suite) -> [sys1, call_format_status]. +sys(suite) -> [sys1, call_format_status, error_format_status]. sys1(Config) when is_list(Config) -> ?line {ok, Pid} = @@ -324,6 +324,27 @@ call_format_status(Config) when is_list(Config) -> ?line [format_status_called | _] = lists:reverse(Data), ?line stop_it(Pid). +error_format_status(Config) when is_list(Config) -> + ?line error_logger_forwarder:register(), + OldFl = process_flag(trap_exit, true), + StateData = "called format_status", + ?line {ok, Pid} = gen_fsm:start(gen_fsm_SUITE, {state_data, StateData}, []), + %% bad return value in the gen_fsm loop + ?line {'EXIT',{{bad_return_value, badreturn},_}} = + (catch gen_fsm:sync_send_event(Pid, badreturn)), + receive + {error,_GroupLeader,{Pid, + "** State machine"++_, + [Pid,{_,_,badreturn},idle,StateData,_]}} -> + ok; + Other -> + ?line io:format("Unexpected: ~p", [Other]), + ?line ?t:fail() + end, + ?t:messages_get(), + process_flag(trap_exit, OldFl), + ok. + %% Hibernation hibernate(suite) -> []; @@ -704,6 +725,8 @@ init(hiber) -> {ok, hiber_idle, []}; init(hiber_now) -> {ok, hiber_idle, [], hibernate}; +init({state_data, StateData}) -> + {ok, idle, StateData}; init(_) -> {ok, idle, state_data}. @@ -844,5 +867,7 @@ handle_sync_event(stop_shutdown_reason, _From, _State, Data) -> handle_sync_event({get, _Pid}, _From, State, Data) -> {reply, {state, State, Data}, State, Data}. -format_status(_Opt, [_Pdict, _StateData]) -> +format_status(terminate, [_Pdict, StateData]) -> + StateData; +format_status(normal, [_Pdict, _StateData]) -> [format_status_called]. diff --git a/lib/stdlib/test/gen_server_SUITE.erl b/lib/stdlib/test/gen_server_SUITE.erl index 0f60c2c4ee..0966734c89 100644 --- a/lib/stdlib/test/gen_server_SUITE.erl +++ b/lib/stdlib/test/gen_server_SUITE.erl @@ -31,7 +31,7 @@ spec_init_local_registered_parent/1, spec_init_global_registered_parent/1, otp_5854/1, hibernate/1, otp_7669/1, call_format_status/1, - call_with_huge_message_queue/1 + error_format_status/1, call_with_huge_message_queue/1 ]). % spawn export @@ -52,7 +52,8 @@ all(suite) -> call_remote_n2, call_remote_n3, spec_init, spec_init_local_registered_parent, spec_init_global_registered_parent, - otp_5854, hibernate, otp_7669, call_format_status, + otp_5854, hibernate, otp_7669, + call_format_status, error_format_status, call_with_huge_message_queue]. -define(default_timeout, ?t:minutes(1)). @@ -897,7 +898,7 @@ call_format_status(doc) -> ["Test that sys:get_status/1,2 calls format_status/2"]; call_format_status(Config) when is_list(Config) -> ?line {ok, Pid} = gen_server:start_link({local, call_format_status}, - gen_server_SUITE, [], []), + ?MODULE, [], []), ?line Status1 = sys:get_status(call_format_status), ?line {status, Pid, _Mod, [_PDict, running, _Parent, _, Data1]} = Status1, ?line [format_status_called | _] = lists:reverse(Data1), @@ -906,6 +907,35 @@ call_format_status(Config) when is_list(Config) -> ?line [format_status_called | _] = lists:reverse(Data2), ok. +%% Verify that error termination correctly calls our format_status/2 fun +%% +error_format_status(suite) -> + []; +error_format_status(doc) -> + ["Test that an error termination calls format_status/2"]; +error_format_status(Config) when is_list(Config) -> + ?line error_logger_forwarder:register(), + OldFl = process_flag(trap_exit, true), + State = "called format_status", + ?line {ok, Pid} = gen_server:start_link(?MODULE, {state, State}, []), + ?line {'EXIT',{crashed,_}} = (catch gen_server:call(Pid, crash)), + receive + {'EXIT', Pid, crashed} -> + ok + end, + receive + {error,_GroupLeader,{Pid, + "** Generic server"++_, + [Pid,crash,State,crashed]}} -> + ok; + Other -> + ?line io:format("Unexpected: ~p", [Other]), + ?line ?t:fail() + end, + ?t:messages_get(), + process_flag(trap_exit, OldFl), + ok. + %% Test that the time for a huge message queue is not %% significantly slower than with an empty message queue. call_with_huge_message_queue(Config) when is_list(Config) -> @@ -1105,5 +1135,7 @@ terminate({From, stopped_info}, _State) -> terminate(_Reason, _State) -> ok. -format_status(_Opt, [_PDict, _State]) -> - [format_status_called]. +format_status(terminate, [_PDict, State]) -> + State; +format_status(normal, [_PDict, _State]) -> + format_status_called. |