Weird behaviour when using around_transition & around_save together

[saurabhnanda]

Hi,

I'm vexed by extremely weird behaviour while using around_transition and around_save on the same model. It could be that this is not a bug, and I'm missing something extremely simple - please pardon me in that case. However, to the best of my understanding, this seems to be some bug somewhere.

Here's a PoC code which produces this bug.

Note: RequestStore is a Gem which allows you to keep stuff in Thread.current safely.

class Foo < ActiveRecord::Base
  attr_accessible :description, :name, :state

  state_machine :initial => :incomplete do
    event :activate do 
        transition :incomplete => :active
    end
    event :deactivate do
        transition :active => :inactive
    end

    around_transition do |record, transition, block|
        RequestStore.store[:current_event] ||= []
        begin
            RequestStore.store[:current_event].push(transition.event.to_s)
            puts "** around_transition / before calling block #{RequestStore.store[:current_event]}"
            block.call
            puts "** around_transition / after calling block #{RequestStore.store[:current_event]}"
        ensure
            puts "** around_transition / in ensure #{RequestStore.store[:current_event]}"
            RequestStore.store[:current_event].pop
        end
    end
  end

  around_save :create_audit

  def create_audit
    puts "** create_audit / before yielding #{RequestStore.store[:current_event]}"
    ret = yield
    puts "** create_audit / after yielding #{RequestStore.store[:current_event]}"
    puts " ... would've created the audit log here"
  end

  def current_event
    (RequestStore.store[:current_event] || []).last
  end
end

I would expect the following output during a state transition (in the following examples the event is, say 'activate'):

** around_transition / before calling block ["activate"]
** create_audit / before yielding ["activate"]
** create_audit / after yielding ["activate"]
 ... would've created the audit log here
** around_transition / after calling block ["activate"]
** around_transition / in ensure ["activate"]

However, the actual output is:

** around_transition / before calling block ["activate"]
** around_transition / in ensure ["activate"]  ## NOTICE the bizarre call to the ensure block at this point?!
** create_audit / before yielding []
** create_audit / after yielding []
 ... would've created the audit log here
** around_transition / after calling block []
** around_transition / in ensure []

Any clue as to what could be going wrong? Am I doing something really stupid here?

I've made a quick Rails app with the PoC code at https://github.com/saurabhnanda/test_state_machine You can create this output by rails r lib/test_script.rb

[the8472]

Maybe this is a side-effect of using continuations for the around callbacks?

[saurabhnanda]

So, it is a bug and not something stupid from my end?

Saurabh

http://www.saurabhnanda.com On 1 Feb 2013 18:45, "the8472" notifications@github.com wrote:

Maybe this is a side-effect of using continuations for the around callbacks?

— Reply to this email directly or view it on GitHubhttps://github.com/pluginaweek/state_machine/issues/230#issuecomment-12993536.

[the8472]

I think this is simply wonky behavior of ensure blocks in the presence of continuations. See https://github.com/rubinius/rubinius/blob/master/spec/ruby/shared/continuation/call.rb#L35

[saurabhnanda]

Any advantage of using continuations vs blocks within state_machine?

On Sat, Feb 2, 2013 at 5:20 PM, the8472 notifications@github.com wrote:

I think this is simply wonky behavior of ensure blocks in the presence of continuations. See https://github.com/rubinius/rubinius/blob/master/spec/ruby/shared/continuation/call.rb#L35

— Reply to this email directly or view it on GitHubhttps://github.com/pluginaweek/state_machine/issues/230#issuecomment-13028278.

http://www.saurabhnanda.com

[saurabhnanda]

Also, are only around_transition implemented through continuations? What about before & after transition.

[the8472]

before and after are called in a plain loop, I think.

[obrie]

Indeed this was an issue with the use of continuations. However, the fact that state_machine was using a continuation in the first place was a bug in this case. I've updated the ORM integrations to fix this issue -- with the upcoming 1.2.0 release you should no longer see this under most circumstances.

Thanks for reporting this issue and @the8472 thanks for the suggested workarounds!

[saurabhnanda]

Thank you for fixing this :-)