Fix prepend/append action hooks firing multiple times

This addresses the surprising behavior that the StoreBoxMetadata hook
was running many times during a machine up, including during failed
operations where a destroy_on_error deleted the machine. This was
resulting in an error that looked like:

> No such file or directory @ rb_sysopen [...] /[...]/box_meta

Plugin action hooks using prepend/append were attaching every time a
Builder was run, including sub-Builders that show up for things like
Call actions.

To fix this, we tell Builders if they are "primary" and only run
prepend/append on those. See inline comments for more explanation.

lib/vagrant/action.rb

@@ -2,10 +2,11 @@ require 'vagrant/action/builder'
 
 module Vagrant
   module Action
-    autoload :Builder,     'vagrant/action/builder'
-    autoload :Hook,        'vagrant/action/hook'
-    autoload :Runner,      'vagrant/action/runner'
-    autoload :Warden,      'vagrant/action/warden'
+    autoload :Builder,       'vagrant/action/builder'
+    autoload :Hook,          'vagrant/action/hook'
+    autoload :Runner,        'vagrant/action/runner'
+    autoload :PrimaryRunner, 'vagrant/action/primary_runner'
+    autoload :Warden,        'vagrant/action/warden'
 
     # Builtin contains middleware classes that are shipped with Vagrant-core
     # and are thus available to all plugins as a "standard library" of sorts.

lib/vagrant/action/builder.rb

@@ -28,6 +28,36 @@ module Vagrant
       # @return [Array]
       attr_reader :stack
 
+      # Action Hooks allow plugin authors to inject their code wherever they
+      # want in the action stack. The methods they get are:
+      #
+      #   - prepend/append, which puts their middleware at the beginning or end
+      #     of the whole stack
+      #   - before/after, which attaches their middleware to an existing item
+      #     in the stack
+      #
+      # Applying Action Hooks properly gets tricky because the action stack
+      # becomes deeply nested with things like Action::Builtin::Call and
+      # Builder#use(other_builder). The way it breaks down is:
+      #
+      #  - prepend/append hooks should be applied only at the top level stack,
+      #    so they run once at the beginning or end
+      #  - before/after hooks should be applied in every sub-builder, because
+      #    they will only actually attach if they find their target sibling
+      #
+      # We achieve this behavior by tracking if we are a "primary" Builder, and
+      # only running prepend/append operations when we are.
+      #
+      # Note this difference only applies to action_hooks registered with
+      # machine action names and not action_hooks which reference middleware
+      # directly, which only support prepend/append and are handled in
+      # #apply_dynamic_updates.
+      #
+      # @return [Boolean] true if this is a primary / top-level Builder
+      # @see Vagrant::Action::PrimaryRunner
+      # @see Vagrant::Action::Hook
+      attr_accessor :primary
+
       # This is a shortcut for a middleware sequence with only one item
       # in it. For a description of the arguments and the documentation, please
       # see {#use} instead.
@@ -39,6 +69,7 @@ module Vagrant
 
       def initialize
         @stack = []
+        @logger = Log4r::Logger.new("vagrant::action::builder")
       end
 
       # Implement a custom copy that copies the stack variable over so that
@@ -311,7 +342,11 @@ module Vagrant
         return self if hook.empty?
 
         # Apply all the hooks to the new builder instance
-        hook.apply(self)
+        hook.apply(self, {
+          # Only primary builders run prepend/append, otherwise nested builders
+          # would duplicate hooks. See explanation at self#primary.
+          no_prepend_or_append: !primary,
+        })
 
         self
       end

lib/vagrant/action/primary_runner.rb

@@ -0,0 +1,15 @@
+module Vagrant
+  module Action
+    # A PrimaryRunner is a special kind of "top-level" Action::Runner - it
+    # informs any Action::Builders it interacts with that they are also
+    # primary. This allows Builders to distinguish whether or not they are
+    # nested, which they need to know for proper action_hook handling.
+    #
+    # @see Vagrant::Action::Builder#primary
+    class PrimaryRunner < Runner
+      def primary?
+        true
+      end
+    end
+  end
+end

lib/vagrant/action/runner.rb

@@ -9,12 +9,20 @@ module Vagrant
     class Runner
       @@reported_interrupt = false
 
+      # @param globals [Hash] variables for the env to be passed to the action
+      # @yieldreturn [Hash] lazy-loaded vars merged into the env before action run
       def initialize(globals=nil, &block)
         @globals      = globals || {}
         @lazy_globals = block
         @logger       = Log4r::Logger.new("vagrant::action::runner")
       end
 
+      # @see PrimaryRunner
+      # @see Vagrant::Action::Builder#primary
+      def primary?
+        false
+      end
+
       def run(callable_id, options=nil)
         callable = callable_id
         if !callable.kind_of?(Builder)
@@ -28,6 +36,10 @@ module Vagrant
             "Argument to run must be a callable object or registered action."
         end
 
+        if callable.is_a?(Builder)
+          callable.primary = self.primary?
+        end
+
         # Create the initial environment with the options given
         environment = {}
         environment.merge!(@globals)

lib/vagrant/environment.rb

@@ -190,10 +190,10 @@ module Vagrant
 
       # Call the hooks that does not require configurations to be loaded
       # by using a "clean" action runner
-      hook(:environment_plugins_loaded, runner: Action::Runner.new(env: self))
+      hook(:environment_plugins_loaded, runner: Action::PrimaryRunner.new(env: self))
 
       # Call the environment load hooks
-      hook(:environment_load, runner: Action::Runner.new(env: self))
+      hook(:environment_load, runner: Action::PrimaryRunner.new(env: self))
     end
 
     # Return a human-friendly string for pretty printed or inspected
@@ -208,7 +208,7 @@ module Vagrant
     #
     # @return [Action::Runner]
     def action_runner
-      @action_runner ||= Action::Runner.new do
+      @action_runner ||= Action::PrimaryRunner.new do
         {
           action_runner:  action_runner,
           box_collection: boxes,

test/unit/vagrant/action/builder_test.rb

@@ -2,6 +2,12 @@ require File.expand_path("../../../base", __FILE__)
 
 describe Vagrant::Action::Builder do
   let(:data) { { data: [] } }
+  let(:primary) { true }
+  let(:subject) do
+    described_class.new.tap do |b|
+      b.primary = primary
+    end
+  end
 
   # This returns a proc that can be used with the builder
   # that simply appends data to an array in the env.
@@ -344,7 +350,7 @@ describe Vagrant::Action::Builder do
     end
 
     it "should call hook before running action" do
-      instance = described_class.build(ActionTwo)
+      instance = described_class.build(ActionTwo).tap { |b| b.primary = true }
       instance.call(data)
       expect(data[:data].first).to eq(:first)
       expect(data[:data].last).to eq(2)
@@ -359,8 +365,8 @@ describe Vagrant::Action::Builder do
       end
 
       it "should execute the hook" do
-        described_class.build(ActionTwo).call(data)
-        described_class.build(ActionOne).call(data)
+        described_class.build(ActionTwo).tap { |b| b.primary = true }.call(data)
+        described_class.build(ActionOne).tap { |b| b.primary = true }.call(data)
         expect(data[:data]).to include(:first)
       end
     end
@@ -374,14 +380,14 @@ describe Vagrant::Action::Builder do
       end
 
       it "should execute the hook" do
-        described_class.build(ActionTwo).call(data)
-        described_class.build(ActionOne).call(data)
+        described_class.build(ActionTwo).tap { |b| b.primary = true }.call(data)
+        described_class.build(ActionOne).tap { |b| b.primary = true }.call(data)
         expect(data[:data]).to include(:first)
       end
 
       it "should execute the hook multiple times" do
-        described_class.build(ActionTwo).call(data)
-        described_class.build(ActionOne).call(data)
+        described_class.build(ActionTwo).tap { |b| b.primary = true }.call(data)
+        described_class.build(ActionOne).tap { |b| b.primary = true }.call(data)
         expect(data[:data].count{|d| d == :first}).to eq(2)
       end
     end
@@ -519,6 +525,7 @@ describe Vagrant::Action::Builder do
 
     let(:subject) do
       @subject ||= described_class.new.tap do |b|
+        b.primary = primary
         b.use Vagrant::Action::Builtin::EnvSet
         b.use Vagrant::Action::Builtin::Confirm
       end
@@ -673,6 +680,7 @@ describe Vagrant::Action::Builder do
 
     let(:subject) do
       @subject ||= described_class.new.tap do |b|
+        b.primary = primary
         b.use Vagrant::Action::Builtin::EnvSet
         b.use Vagrant::Action::Builtin::Confirm
       end
@@ -681,7 +689,7 @@ describe Vagrant::Action::Builder do
     before { allow(triggers).to receive(:find).and_return([]) }
     after { @subject = nil }
 
-    context "when a plugin has added an action hook" do
+    context "when a plugin has added an action hook using prepend" do
       let(:plugin) do
         @plugin ||= Class.new(Vagrant.plugin("2")) do
           name "Test Plugin"
@@ -698,7 +706,7 @@ describe Vagrant::Action::Builder do
         @plugin = nil
       end
 
-      it "should add new action to the call stack" do
+      it "should add new action to the beginning of the call stack" do
         subject.apply_action_name(env)
         expect(subject.stack[0].first).to eq(Vagrant::Action::Builtin::Call)
       end