[erlang-questions] gen_statem: next event internal and reply

[Peter Morgan]

Hi,

I regularly use the following pattern in gen_statem:

handle_event({call, From}, a, _, _) ->
  {keep_state_and_data, [{next_event, internal, work}, {reply, From, ok}]};

Where `work` is some side effect that needs to be done, and may be used by several other actions (hence wrapping it in a next_event) but the result is unimportant and doesn’t affect the reply. I use  next_event rather than calling work() directly because it can be traced via sys.

My assumption was that work would be processed before the reply was sent to the caller - i.e., that the actions were processed in order.

Instead, it appears that the reply action is processed immediately?

To work around this I have started using:

handle_event({call, From}, a, _, _) ->
  {keep_state_and_data, [{next_event, internal, work}, {next_event, internal, {reply, From, ok}]}};
handle_event(internal, {reply, From, Result}, _, _) ->
    {keep_state_and_data, {reply, From, Result}}.

The above ensures that work is completed before the reply is sent (result of the work is a side-effect here) - but is a rather ugly solution.

Is the above intended behaviour? In some cases the `work` event causes state changes, or queueing subsequent other work (via next_event, internal) that was expected to be completed before the {reply, From, ok} was consumed.

The above ordering of actions assumption caught me out recently, the early reply was causing a process to be killed before it had actually completed its work causing an unclean shutdown in a system.

BTW the additional of log is very useful in failure analysis - what did this statem recently do? :) thanks!


Thanks,
Peter.

Full example:

-module(exaple_statem_reply).

-behaviour(gen_statem).
-export([a/0]).
-export([b/0]).
-export([callback_mode/0]).
-export([handle_event/4]).
-export([init/1]).
-export([start/0]).
-export([stop/1]).
-include_lib("kernel/include/logger.hrl").

start() ->
    gen_statem:start({local, ?MODULE},
                     ?MODULE,
                    [],
                    [{debug, [log, trace]}]).

a() ->
    gen_statem:call(?MODULE, ?FUNCTION_NAME).

b() ->
    gen_statem:call(?MODULE, ?FUNCTION_NAME).

stop(S) ->
    gen_statem:stop(S).

init([]) ->
    {ok, limbo, #{}}.


callback_mode() ->
    handle_event_function.

handle_event({call, From}, a, _, _) ->
    {keep_state_and_data, [nei(work), {reply, From, ok}]};

handle_event({call, From}, b, _, _) ->
    {keep_state_and_data, [nei(work), nei({reply, From, ok})]};

handle_event(internal, work, _, _) ->
    keep_state_and_data;

handle_event(internal, {reply, From, Result}, _, _) ->
    {keep_state_and_data, {reply, From, Result}}.

nei(Event) ->
    {next_event, internal, Event}.


1>   exaple_statem_reply:start().
*DBG* exaple_statem_reply enter in state limbo
*DBG* exaple_statem_reply consume internal init_state in state limbo
{ok,<0.161.0>}
2>   exaple_statem_reply:a().
*DBG* exaple_statem_reply receive call a from <0.78.0> in state limbo
*DBG* exaple_statem_reply receive internal work in state limbo
*DBG* exaple_statem_reply send ok to <0.78.0>
*DBG* exaple_statem_reply consume call a from <0.78.0> in state limbo
ok
*DBG* exaple_statem_reply consume internal work in state limbo
3>   sys:get_status(exaple_statem_reply).
{status,<0.161.0>,
        {module,gen_statem},
        [[{'$ancestors',[<0.78.0>]},
          {'$initial_call',{exaple_statem_reply,init,1}}],
         running,<0.161.0>,
         [{trace,true},
          {log,[3,
                {{consume,{internal,work},limbo,limbo},
                 exaple_statem_reply,#Fun<gen_statem.1.50707408>},
                {{consume,{{call,{<0.78.0>,
                                  #Ref<0.2400559651.2919759873.28633>}},
                           a},
                          limbo,limbo},
                 exaple_statem_reply,#Fun<gen_statem.1.50707408>},
                {{out,ok,{<0.78.0>,#Ref<0.2400559651.2919759873.28633>}},
                 exaple_statem_reply,#Fun<gen_statem.1.50707408>},
                {{in,{internal,work},limbo},
                 exaple_statem_reply,#Fun<gen_statem.1.50707408>},
                {{in,{{call,{<0.78.0>,#Ref<0.2400559651.2919759873.28633>}},
                      a},
                     limbo},
                 exaple_statem_reply,#Fun<gen_statem.1.50707408>},
                {{consume,{internal,init_state},limbo,limbo},
                 exaple_statem_reply,#Fun<gen_statem.1.50707408>},
                {{enter,limbo},
                 exaple_statem_reply,#Fun<gen_statem.1.50707408>}]}],
         [{header,"Status for state machine exaple_statem_reply"},
          {data,[{"Status",running},
                 {"Parent",<0.161.0>},
                 {"Logged Events",
                  [{enter,limbo},
                   {consume,{internal,init_state},limbo,limbo},
                   {in,{{call,{<0.78.0>,#Ref<0.2400559651.2919759873.28633>}},
                        a},
                       limbo},
                   {in,{internal,work},limbo},
                   {out,ok,{<0.78.0>,#Ref<0.2400559651.2919759873.28633>}},
                   {consume,{{call,{...}},a},limbo,limbo},
                   {consume,{internal,work},limbo,limbo}]},
                 {"Postponed",[]}]},
          {data,[{"State",{limbo,#{}}}]}]]}
4> 


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://erlang.org/pipermail/erlang-questions/attachments/20190731/a1adc7e0/attachment.htm>