Operation is invoked multiple times after code reloading in dev env

[Mehonoshin]

Hello, everyone!

I have an extremely simple TRB operation:

module BA
  module Test
    class Action < Trailblazer::Operation
      success :run_method!

      private

      def run_method!(options, **)
        puts "Method is invoked!"
      end
    end
  end
end

Here is an example of PRY session, the same is happening when Rails server is started.

[1] pry(main)> BA::Test::Action.()
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!]}> >
[2] pry(main)> BA::Test::Action.()
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!]}> >
[3] pry(main)> BA::Test::Action.()
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!]}> >
[4] pry(main)> reload!
Reloading...
=> true
[5] pry(main)> BA::Test::Action.()
Method is invoked!
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!,>run_method!]}> >
[6] pry(main)> BA::Test::Action.()
Method is invoked!
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!,>run_method!]}> >
[7] pry(main)> BA::Test::Action.()
Method is invoked!
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!,>run_method!]}> >
[8] pry(main)> reload!
Reloading...
=> true
[9] pry(main)> BA::Test::Action.()
Method is invoked!
Method is invoked!
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!,>run_method!,>run_method!]}> >

It should be related to rails autoloading&reloading, and probably not connected with TRB::Operation, but I'd like to hear your opinion.

[apotonick]

This is a problem with Rails' reloading, are you using spring?

[Mehonoshin]

I don't use spring, and I understand that it is related to rails, but maybe we can fix that at trailblazer somehow? Any instant ideas where I should look for the problem? I'm not so familiar with TRB internals, yet.

[apotonick]

All we do is using class instance variables to save DSL state, which is a very common pattern. Maybe you can test "our" behavior without using trailblazer-loader or even without trailblazer-rails to eliminate error sources?

Thanks for helping! :beers:

[Mehonoshin]

It looks like this bug is reproducible only in combination of rails reload and TRB::Loader

~/p/trb_debug(master ✗) rc
Loading development environment (Rails 5.1.4)

irb(main):001:0> reload!
Reloading...
=> true
irb(main):002:0> Trailblazer::Loader.new.() { |file| require_dependency(File.join(Rails.application.root, file)) }
=> ["./app/concepts/ba/test/action.rb"]
irb(main):003:0> BA::Test::Action.()
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!]}> >

irb(main):004:0> reload!
Reloading...
=> true
irb(main):005:0> Trailblazer::Loader.new.() { |file| require_dependency(File.join(Rails.application.root, file)) }
=> ["./app/concepts/ba/test/action.rb"]
irb(main):006:0> BA::Test::Action.()
Method is invoked!
Method is invoked!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!,>run_method!]}> >

I'm looking forward to finding the root cause and fix it.

[Mehonoshin]

Some new findings, for history

if we add some logging to https://github.com/Mehonoshin/trailblazer-operation/blob/923d26335b8b973ec12587aabe979a5c8f5bbe61/lib/trailblazer/operation/pipetree.rb#L30 like

      def call(options)
        pipe = self["pipetree"] # TODO: injectable? WTF? how cool is that?
        puts pipe.inspect

        last, operation = pipe.(self, options)

        # Any subclass of Right will be interpreted as successful.
        Result.new(!!(last <= Railway::Right), options)
      end

We will get the following output, that means that after code reload with rails, we have several pointers to the same method at operation pipe:

~/p/trb_debug(master ✗) rc
Loading development environment (Rails 5.1.4)
irb(main):001:0> BA::Test::Action.()
[>operation.new,>run_method!]
Method is invoked2!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!]}> >
irb(main):002:0> reload!
Reloading...
=> true
irb(main):003:0> BA::Test::Action.()
[>operation.new,>run_method!,>run_method!]
Method is invoked2!
Method is invoked2!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!,>run_method!]}> >
irb(main):004:0> reload!
Reloading...
=> true
irb(main):005:0> BA::Test::Action.()
[>operation.new,>run_method!,>run_method!,>run_method!]
Method is invoked2!
Method is invoked2!
Method is invoked2!
=> <Result:true <Skill {} {"params"=>{}} {"pipetree"=>[>operation.new,>run_method!,>run_method!,>run_method!]}> >
irb(main):006:0>

[apotonick]

So you tried to remove trb-loader? How did you load the files, instead?

[ffloyd]

@Mehonoshin You may try to use my gem heavy_control instead of trb-loader. Also It has small autoloading debugging feature which may be useful while investigate such issues.

[iJackUA]

@Mehonoshin I suppose I had the same issues https://speakerdeck.com/ijackua/organizing-an-architecture-of-your-ruby-on-rails-app-with-trailblazer-2-dot-0?slide=48 and use this workaround with adding initialize_pipetree! as the easiest https://speakerdeck.com/ijackua/organizing-an-architecture-of-your-ruby-on-rails-app-with-trailblazer-2-dot-0?slide=49

Rails just reload classes and steps are being added to the pipe multiple times, with initialize_pipetree! we flush the pipetree on each reload. Maybe it is better to incorporate into TRB-Rails integration, but personally, I don't have a mental forces for this :)

[Mehonoshin]

@ffloyd @iJackUA thank you for your solutions, guys! I've also made some workarounds, but it's great that this topic attracts attention. Because such bugs are really frustrating.

[apotonick]

The problem with your fixes @iJackUA and @Mehonoshin is that it won't work in 2.1 because the internals have changed!

Anyway the amazing @fxn helped us out :heart: with this code snippet: https://github.com/dry-rb/dry-types/issues/18#issuecomment-357450577 So maybe this will lead to autoloading and Trailblazer finally liking each other?

[iJackUA]

@apotonick would you have smth similar to initialize_pipetree! in new internal API to reset a pipeline? To use as dirty hack while we are dreaming about a good solytion :)

[mgraham]

You can duplicate the issue with pure Trailblazer like this:

load "app/concepts/ba/test/operations/action.rb"
load "app/concepts/ba/test/operations/action.rb"
load "app/concepts/ba/test/operations/action.rb"
BA::Test::Action.()

I discovered this issue when I tried to run Trailblazer 2 in rspec-console, which is a persistent testing environment.

I'm pretty sure it caches classes similar to how Rails does. To get around this, I was using load instead of require, which had the unfortunate side effect of duplicating all steps in the Trailblazer Operation.

[apotonick]

There's no caching in TRB, we simply use class instance variables for DSL state (e.g. to collect steps). I am not an expert on Rails' autoloading and I really don't want to be one. What we do is turn off the TRB loader entirely (in Rails!), name OPs following the Rails Way Ba::Operation::Action and things work as expected, including reloading.

[iJackUA]

Actually, kind-a such problem happens in Hanami for example (not Rails or loader specific). In dev env with Shotgun reload it works fine and does not cause duplications. But when one Operation uses another Nested Operation - I do manual "require" to make sure that nested op is included before enclosing one. And it makes Nested operation steps to fire twice - as it was kind-a "interpreted" by Ruby twice: first time when required by another OP and one more time when found by Hanami loader and "reloaded". It is a rear but existing case. At the moment I fix it with workaround

class MyOp
... 
end unless !defined? MyOp

but ideally I am thingking about making some wrapper block around steps declaration in operation, to hide this explicit check and prevent steps redeclration if some steps already exist in pipeline. (I am not sure it is possible :) )

[sadjow]

@Mehonoshin @iJackUA If your folders tree include operations folder, it is needed to have the Operations namespace. Your namespace should follow the folders, so that you will not have problems with auto-reloading in dev env. Just to clarify what @apotonick said.

module BA
  module Test
    # bellow add the Operations:: this is needed, without it Rails will load again and again in dev.
    class Operations::Action < Trailblazer::Operation
      success :run_method!

      private

      def run_method!(options, **)
        puts "Method is invoked!"
      end
    end
  end
end

[rosskevin]

As an aside for those that may find this, we found similar symptoms: seemed like an operation executing twice, but it was actually once with the steps were duplicated due to operation inheritance. We switched to operation composition instead and solved our issue.

[apotonick]

If you disable the loader, those problems should go away: http://trailblazer.to/2.1/index.html#loader

[fernandes]

I disabled the loader, but then my locales inside concepts/views aren't loaded, any idea why?

[apotonick]

They are no longer required automatically.