[erlang-questions] gen_statem - state_timeout sometimes reaching callback module as [info, {timeout, Ref, Name}

[Peter Morgan]

Hello -

We are _sometimes_ seeing cases where a state_timeout in a gen_statem results in the timeout reaching the callback module as info {timeout, Ref, Name} with OTP 21.2.

The crash looks like:

=ERROR REPORT==== 8-Apr-2019::23:37:19.035346 === <0.969.0> gen_statem:error_info/5:1895
** State machine {kafire_fetcher,<<“abc">>,<<“def">>,0} terminating
** Last event = {info,{timeout,#Ref<0.2399112782.889192450.118024>,fetch}}

We crash because we are not expecting info messages - interestingly the following messages are in the queue for the crashed process:


    message_queue_len: 279
    messages: [{timeout,#Ref<0.2399112782.903610369.70160>,fetch},
                  {cancel_timer,#Ref<0.2399112782.903610369.70160>,false},
                  {cancel_timer,#Ref<0.2399112782.903610369.70168>,4},
                  {cancel_timer,#Ref<0.2399112782.889192450.118038>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118039>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118043>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118044>,4},
                  {cancel_timer,#Ref<0.2399112782.889192450.118045>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118049>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118050>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118051>,4},
                  {cancel_timer,#Ref<0.2399112782.889192450.118052>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118053>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118054>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118055>,4},
                  {cancel_timer,#Ref<0.2399112782.889192450.118056>,5},
                  {cancel_timer,#Ref<0.2399112782.889192450.118060>,5},

Followed by lots more cancel_timer messages (200ish!). Our gen_statem does use {state_timeout, 500, fetch} so we are expecting a “fetch” timeout to happen, and we use repeat_state_and_data to requeue the state timeout (and also transition to other states). Is it possible that timeouts in gen_statem can be delivered as an info message?

Thanks
Peter.

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