From 070199e87743196300151364df34297c26301f83 Mon Sep 17 00:00:00 2001
From: mattkirby <kirby@puppetlabs.com>
Date: Fri, 13 Jul 2018 10:06:44 -0700
Subject: [PATCH] Eliminate duplicate VM object lookups where possible (#269)

* Minimize duplicate checking of VMs

This commit updates check_pool pending, running and ready methods to greatly reduce instances in which the VM object is retrieved. Without this change get_vm is run for each of these check_pool steps even though the VM is already validated as being in inventory being running the check. This is left for checking running VMs when the VM is no longer ready. Without this change there is an unnecessarily large volume of VM object checks.

* Make hostname mismatch checking optional

This commit makes hostname mismatch checking optional on a pool and global config level. The default behavior of checking this is preserved. When disabled _check_ready_vm will not run get_vm, which allows for ready VMs to be checked without retrieving an object from vsphere and waiting for a free provider connection. Without this change it is not possible to disable VM object retrieval in _check_vm_ready.

* Check if a hostname return is empty string

This commit checks whether a hostname returned is an empty string.
Without this change a VM that returns a hostname with a empty string
will report as having a hostname mismatch, which may happen before all
VM data is updated.

* Only check hostname for mismatch after time since ready has past

Configure hostname checking so it is not checked until a VM has been
ready for greater than one minute. Without this change hostname checking
will often fail because the configured value has not propogated to the
VM on some platforms before this check is run.
---
 lib/vmpooler/pool_manager.rb   | 135 +++++++++----------
 spec/unit/pool_manager_spec.rb | 229 ++++++++++++++-------------------
 2 files changed, 164 insertions(+), 200 deletions(-)

diff --git a/lib/vmpooler/pool_manager.rb b/lib/vmpooler/pool_manager.rb
index 15e2dfb..e7159ae 100644
--- a/lib/vmpooler/pool_manager.rb
+++ b/lib/vmpooler/pool_manager.rb
@@ -49,13 +49,8 @@ module Vmpooler
       mutex = vm_mutex(vm)
       return if mutex.locked?
       mutex.synchronize do
-        host = provider.get_vm(pool, vm)
-        unless host
-          fail_pending_vm(vm, pool, timeout, false)
-          return
-        end
         if provider.vm_ready?(pool, vm)
-          move_pending_vm_to_ready(vm, pool, host)
+          move_pending_vm_to_ready(vm, pool)
         else
           fail_pending_vm(vm, pool, timeout)
         end
@@ -86,25 +81,27 @@ module Vmpooler
       false
     end
 
-    def move_pending_vm_to_ready(vm, pool, host)
-      if host['hostname'] == vm
-        begin
-          Socket.getaddrinfo(vm, nil) # WTF? I assume this is just priming the local DNS resolver cache?!?!
-        rescue # rubocop:disable Lint/HandleExceptions
-          # Do not care about errors what-so-ever
-        end
+    def move_pending_vm_to_ready(vm, pool)
+      clone_time = $redis.hget('vmpooler__vm__' + vm, 'clone')
+      finish = format('%.2f', Time.now - Time.parse(clone_time)) if clone_time
 
-        clone_time = $redis.hget('vmpooler__vm__' + vm, 'clone')
-        finish = format('%.2f', Time.now - Time.parse(clone_time)) if clone_time
+      $redis.smove('vmpooler__pending__' + pool, 'vmpooler__ready__' + pool, vm)
+      $redis.hset('vmpooler__boot__' + Date.today.to_s, pool + ':' + vm, finish) # maybe remove as this is never used by vmpooler itself?
+      $redis.hset("vmpooler__vm__#{vm}", 'ready', Time.now)
 
-        $redis.smove('vmpooler__pending__' + pool, 'vmpooler__ready__' + pool, vm)
-        $redis.hset('vmpooler__boot__' + Date.today.to_s, pool + ':' + vm, finish) # maybe remove as this is never used by vmpooler itself?
+      # last boot time is displayed in API, and used by alarming script
+      $redis.hset('vmpooler__lastboot', pool, Time.now)
 
-        # last boot time is displayed in API, and used by alarming script
-        $redis.hset('vmpooler__lastboot', pool, Time.now)
-        $metrics.timing("time_to_ready_state.#{pool}", finish)
-        $logger.log('s', "[>] [#{pool}] '#{vm}' moved from 'pending' to 'ready' queue")
-      end
+      $metrics.timing("time_to_ready_state.#{pool}", finish)
+      $logger.log('s', "[>] [#{pool}] '#{vm}' moved from 'pending' to 'ready' queue")
+    end
+
+    def vm_still_ready?(pool_name, vm_name, provider)
+      # Check if the VM is still ready/available
+      return true if provider.vm_ready?(pool_name, vm_name)
+      raise("VM #{vm_name} is not ready")
+    rescue
+      move_vm_queue(pool_name, vm_name, 'ready', 'completed', "is unreachable, removed from 'ready' queue")
     end
 
     def check_ready_vm(vm, pool, ttl, provider)
@@ -112,7 +109,7 @@ module Vmpooler
         begin
           _check_ready_vm(vm, pool, ttl, provider)
         rescue => err
-          $logger.log('s', "[!] [#{pool}] '#{vm}' failed while checking a ready vm : #{err}")
+          $logger.log('s', "[!] [#{pool['name']}] '#{vm}' failed while checking a ready vm : #{err}")
           raise
         end
       end
@@ -126,53 +123,50 @@ module Vmpooler
         check_stamp = $redis.hget('vmpooler__vm__' + vm, 'check')
         return if check_stamp && (((Time.now - Time.parse(check_stamp)) / 60) <= $config[:config]['vm_checktime'])
 
-        host = provider.get_vm(pool, vm)
-        # Check if the host even exists
-        unless host
-          $redis.srem('vmpooler__ready__' + pool, vm)
-          $logger.log('s', "[!] [#{pool}] '#{vm}' not found in inventory, removed from 'ready' queue")
-          return
-        end
-
         $redis.hset('vmpooler__vm__' + vm, 'check', Time.now)
-        # Check if the VM is not powered on, before checking TTL
-        unless host['powerstate'].casecmp('poweredon').zero?
-          $redis.smove('vmpooler__ready__' + pool, 'vmpooler__completed__' + pool, vm)
-          $logger.log('d', "[!] [#{pool}] '#{vm}' appears to be powered off, removed from 'ready' queue")
-          return
-        end
-
         # Check if the hosts TTL has expired
         if ttl > 0
           # host['boottime'] may be nil if host is not powered on
           if ((Time.now - host['boottime']) / 60).to_s[/^\d+\.\d{1}/].to_f > ttl
-            $redis.smove('vmpooler__ready__' + pool, 'vmpooler__completed__' + pool, vm)
+            $redis.smove('vmpooler__ready__' + pool['name'], 'vmpooler__completed__' + pool['name'], vm)
 
-            $logger.log('d', "[!] [#{pool}] '#{vm}' reached end of TTL after #{ttl} minutes, removed from 'ready' queue")
+            $logger.log('d', "[!] [#{pool['name']}] '#{vm}' reached end of TTL after #{ttl} minutes, removed from 'ready' queue")
             return
           end
         end
 
-        # Check if the hostname has magically changed from underneath Pooler
-        if host['hostname'] != vm
-          $redis.smove('vmpooler__ready__' + pool, 'vmpooler__completed__' + pool, vm)
-          $logger.log('d', "[!] [#{pool}] '#{vm}' has mismatched hostname, removed from 'ready' queue")
-          return
-        end
+        return if has_mismatched_hostname?(vm, pool, provider)
 
-        # Check if the VM is still ready/available
-        begin
-          raise("VM #{vm} is not ready") unless provider.vm_ready?(pool, vm)
-        rescue
-          if $redis.smove('vmpooler__ready__' + pool, 'vmpooler__completed__' + pool, vm)
-            $logger.log('d', "[!] [#{pool}] '#{vm}' is unreachable, removed from 'ready' queue")
-          else
-            $logger.log('d', "[!] [#{pool}] '#{vm}' is unreachable, and failed to remove from 'ready' queue")
-          end
-        end
+        vm_still_ready?(pool['name'], vm, provider)
       end
     end
 
+    def has_mismatched_hostname?(vm, pool, provider)
+      check_hostname = pool['check_hostname_for_mismatch']
+      check_hostname = $config[:config]['check_ready_vm_hostname_for_mismatch'] if check_hostname.nil?
+      return if check_hostname == false
+
+      # Wait one minute before checking a VM for hostname mismatch
+      # When checking as soon as the VM passes the ready test the instance
+      # often doesn't report its hostname yet causing the VM to be removed immediately
+      vm_ready_time = $redis.hget("vmpooler__vm__#{vm}", 'ready')
+      if vm_ready_time
+        wait_before_checking = 60
+        time_since_ready = (Time.now - Time.parse(vm_ready_time)).to_i
+        return unless time_since_ready > wait_before_checking
+      end
+
+      # Check if the hostname has magically changed from underneath Pooler
+      vm_hash = provider.get_vm(pool['name'], vm)
+      hostname = vm_hash['hostname']
+
+      return if hostname.empty?
+      return if hostname == vm
+      $redis.smove('vmpooler__ready__' + pool['name'], 'vmpooler__completed__' + pool['name'], vm)
+      $logger.log('d', "[!] [#{pool['name']}] '#{vm}' has mismatched hostname #{hostname}, removed from 'ready' queue")
+      return true
+    end
+
     def check_running_vm(vm, pool, ttl, provider)
       Thread.new do
         begin
@@ -188,17 +182,26 @@ module Vmpooler
       mutex = vm_mutex(vm)
       return if mutex.locked?
       mutex.synchronize do
-        host = provider.get_vm(pool, vm)
+        # Check that VM is within defined lifetime
+        checkouttime = $redis.hget('vmpooler__active__' + pool, vm)
+        if checkouttime
+          running = (Time.now - Time.parse(checkouttime)) / 60 / 60
 
-        if host
-          # Check that VM is within defined lifetime
-          checkouttime = $redis.hget('vmpooler__active__' + pool, vm)
-          if checkouttime
-            running = (Time.now - Time.parse(checkouttime)) / 60 / 60
+          if (ttl.to_i > 0) && (running.to_i >= ttl.to_i)
+            move_vm_queue(pool, vm, 'running', 'completed', "reached end of TTL after #{ttl} hours")
+            return
+          end
+        end
 
-            if (ttl.to_i > 0) && (running.to_i >= ttl.to_i)
-              move_vm_queue(pool, vm, 'running', 'completed', "reached end of TTL after #{ttl} hours")
-            end
+        if provider.vm_ready?(pool, vm)
+          return
+        else
+          host = provider.get_vm(pool, vm)
+
+          if host
+            return
+          else
+            move_vm_queue(pool, vm, 'running', 'completed', "is no longer in inventory, removing from running")
           end
         end
       end
@@ -761,7 +764,7 @@ module Vmpooler
         if inventory[vm]
           begin
             pool_check_response[:checked_ready_vms] += 1
-            check_ready_vm(vm, pool['name'], pool['ready_ttl'] || 0, provider)
+            check_ready_vm(vm, pool, pool['ready_ttl'] || 0, provider)
           rescue => err
             $logger.log('d', "[!] [#{pool['name']}] _check_pool failed with an error while evaluating ready VMs: #{err}")
           end
diff --git a/spec/unit/pool_manager_spec.rb b/spec/unit/pool_manager_spec.rb
index 97196f0..959e838 100644
--- a/spec/unit/pool_manager_spec.rb
+++ b/spec/unit/pool_manager_spec.rb
@@ -64,23 +64,11 @@ EOT
       expect(subject).not_to be_nil
     end
 
-    context 'host does not exist or not in pool' do
-      it 'calls fail_pending_vm' do
-        expect(provider).to receive(:get_vm).with(pool,vm).and_return(nil)
-        expect(subject).to receive(:fail_pending_vm).with(vm, pool, timeout, false) 
-
-        subject._check_pending_vm(vm, pool, timeout, provider)
-      end
-    end
-
     context 'host is in pool' do
-      before do
-        expect(provider).to receive(:get_vm).with(pool,vm).and_return(host)
-      end
 
       it 'calls move_pending_vm_to_ready if host is ready' do
         expect(provider).to receive(:vm_ready?).with(pool,vm).and_return(true)
-        expect(subject).to receive(:move_pending_vm_to_ready).with(vm, pool, host)
+        expect(subject).to receive(:move_pending_vm_to_ready).with(vm, pool)
 
         subject._check_pending_vm(vm, pool, timeout, provider)
       end
@@ -178,35 +166,23 @@ EOT
       subject.fail_pending_vm(vm, pool, timeout,true)
     end
   end
-  
+
   describe '#move_pending_vm_to_ready' do
     let(:host) { { 'hostname' => vm }}
 
     before do
       expect(subject).not_to be_nil
-      allow(Socket).to receive(:getaddrinfo)
     end
 
     before(:each) do
       create_pending_vm(pool,vm)
     end
 
-    context 'when hostname does not match VM name' do
-      it 'should not take any action' do
-        expect(logger).to receive(:log).exactly(0).times
-        expect(Socket).to receive(:getaddrinfo).exactly(0).times
-
-        host['hostname'] = 'different_name'
-
-        subject.move_pending_vm_to_ready(vm, pool, host)
-      end
-    end
-
     context 'when hostname matches VM name' do
       it 'should move the VM from pending to ready pool' do
         expect(redis.sismember("vmpooler__pending__#{pool}", vm)).to be(true)
         expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(false)
-        subject.move_pending_vm_to_ready(vm, pool, host)
+        subject.move_pending_vm_to_ready(vm, pool)
         expect(redis.sismember("vmpooler__pending__#{pool}", vm)).to be(false)
         expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(true)
       end
@@ -214,39 +190,39 @@ EOT
       it 'should log a message' do
         expect(logger).to receive(:log).with('s', "[>] [#{pool}] '#{vm}' moved from 'pending' to 'ready' queue")
 
-        subject.move_pending_vm_to_ready(vm, pool, host)
+        subject.move_pending_vm_to_ready(vm, pool)
       end
 
       it 'should receive time_to_ready_state metric' do
         redis.hset("vmpooler__vm__#{vm}", 'clone',Time.now.to_s)
         expect(metrics).to receive(:timing).with(/time_to_ready_state\./,/0/)
 
-        subject.move_pending_vm_to_ready(vm, pool, host)
+        subject.move_pending_vm_to_ready(vm, pool)
       end
 
 
       it 'should set the boot time in redis' do
         redis.hset("vmpooler__vm__#{vm}", 'clone',Time.now.to_s)
         expect(redis.hget('vmpooler__boot__' + Date.today.to_s, pool + ':' + vm)).to be_nil
-        subject.move_pending_vm_to_ready(vm, pool, host)
+        subject.move_pending_vm_to_ready(vm, pool)
         expect(redis.hget('vmpooler__boot__' + Date.today.to_s, pool + ':' + vm)).to_not be_nil
         # TODO Should we inspect the value to see if it's valid?
       end
 
       it 'should not determine boot timespan if clone start time not set' do
         expect(redis.hget('vmpooler__boot__' + Date.today.to_s, pool + ':' + vm)).to be_nil
-        subject.move_pending_vm_to_ready(vm, pool, host)
+        subject.move_pending_vm_to_ready(vm, pool)
         expect(redis.hget('vmpooler__boot__' + Date.today.to_s, pool + ':' + vm)).to eq("") # Possible implementation bug here. Should still be nil here
       end
 
       it 'should raise error if clone start time is not parsable' do
         redis.hset("vmpooler__vm__#{vm}", 'clone','iamnotparsable_asdate')
-        expect{subject.move_pending_vm_to_ready(vm, pool, host)}.to raise_error(/iamnotparsable_asdate/)
+        expect{subject.move_pending_vm_to_ready(vm, pool)}.to raise_error(/iamnotparsable_asdate/)
       end
 
       it 'should save the last boot time' do
         expect(redis.hget('vmpooler__lastboot', pool)).to be(nil)
-        subject.move_pending_vm_to_ready(vm, pool, host)
+        subject.move_pending_vm_to_ready(vm, pool)
         expect(redis.hget('vmpooler__lastboot', pool)).to_not be(nil)
       end
     end
@@ -254,6 +230,7 @@ EOT
 
   describe '#check_ready_vm' do
     let(:ttl) { 0 }
+    let(:poolconfig) { config[:pools][0] }
 
     before do
       expect(subject).not_to be_nil
@@ -261,15 +238,16 @@ EOT
 
     it 'calls _check_ready_vm' do
       expect(Thread).to receive(:new).and_yield
-      expect(subject).to receive(:_check_ready_vm).with(vm, pool, ttl, provider)
+      expect(subject).to receive(:_check_ready_vm).with(vm, poolconfig, ttl, provider)
 
-      subject.check_ready_vm(vm, pool, ttl, provider)
+      subject.check_ready_vm(vm, poolconfig, ttl, provider)
     end
   end
 
   describe '#_check_ready_vm' do
     let(:ttl) { 0 }
     let(:host) { {} }
+    let(:poolconfig) { config[:pools][0] }
 
     before(:each) do
       create_ready_vm(pool,vm)
@@ -287,40 +265,17 @@ EOT
         check_stamp = (Time.now - 60).to_s
         redis.hset("vmpooler__vm__#{vm}", 'check', check_stamp)
         expect(provider).to receive(:get_vm).exactly(0).times
-        subject._check_ready_vm(vm, pool, ttl, provider)
+        subject._check_ready_vm(vm, poolconfig, ttl, provider)
         expect(redis.hget("vmpooler__vm__#{vm}", 'check')).to eq(check_stamp)
       end
     end
 
-    context 'a VM that does not exist' do
-      before do
-        expect(provider).to receive(:get_vm).with(pool,vm).and_return(nil)
-      end
-
-      it 'should not set the current check timestamp' do
-        expect(redis.hget("vmpooler__vm__#{vm}", 'check')).to be_nil
-        subject._check_ready_vm(vm, pool, ttl, provider)
-        expect(redis.hget("vmpooler__vm__#{vm}", 'check')).to be_nil
-      end
-
-      it 'should log a message' do
-        expect(logger).to receive(:log).with('s', "[!] [#{pool}] '#{vm}' not found in inventory, removed from 'ready' queue")
-        subject._check_ready_vm(vm, pool, ttl, provider)
-      end
-
-      it 'should remove the VM from the ready queue' do
-        expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(true)
-        subject._check_ready_vm(vm, pool, ttl, provider)
-        expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(false)
-      end
-    end
-
     context 'a VM that has never been checked' do
       let(:last_check_date) { Date.new(2001,1,1).to_s }
 
       it 'should set the current check timestamp' do
         expect(redis.hget("vmpooler__vm__#{vm}", 'check')).to be_nil
-        subject._check_ready_vm(vm, pool, ttl, provider)
+        subject._check_ready_vm(vm, poolconfig, ttl, provider)
         expect(redis.hget("vmpooler__vm__#{vm}", 'check')).to_not be_nil
       end
     end
@@ -333,7 +288,7 @@ EOT
 
       it 'should set the current check timestamp' do
         expect(redis.hget("vmpooler__vm__#{vm}", 'check')).to eq(last_check_date)
-        subject._check_ready_vm(vm, pool, ttl, provider)
+        subject._check_ready_vm(vm, poolconfig, ttl, provider)
         expect(redis.hget("vmpooler__vm__#{vm}", 'check')).to_not eq(last_check_date)
       end
 
@@ -343,63 +298,11 @@ EOT
         end
 
         it 'should only set the next check interval' do
-          subject._check_ready_vm(vm, pool, ttl, provider)
+          subject._check_ready_vm(vm, poolconfig, ttl, provider)
         end
       end
 
-      context 'is turned off' do
-        before(:each) do
-          host['powerstate'] = 'PoweredOff'
-        end
-
-        it 'should move the VM to the completed queue' do
-          expect(redis).to receive(:smove).with("vmpooler__ready__#{pool}", "vmpooler__completed__#{pool}", vm)
-
-          subject._check_ready_vm(vm, pool, ttl, provider)
-        end
-
-        it 'should move the VM to the completed queue in Redis' do
-          expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(true)
-          expect(redis.sismember("vmpooler__completed__#{pool}", vm)).to be(false)
-          subject._check_ready_vm(vm, pool, ttl, provider)
-          expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(false)
-          expect(redis.sismember("vmpooler__completed__#{pool}", vm)).to be(true)
-        end
-
-        it 'should log messages about being powered off' do
-          expect(logger).to receive(:log).with('d', "[!] [#{pool}] '#{vm}' appears to be powered off, removed from 'ready' queue")
-
-          subject._check_ready_vm(vm, pool, ttl, provider)
-        end
-      end
-
-      context 'is turned on, a name mismatch' do
-        before(:each) do
-          host['hostname'] = 'different_name'
-        end
-
-        it 'should move the VM to the completed queue' do
-          expect(redis).to receive(:smove).with("vmpooler__ready__#{pool}", "vmpooler__completed__#{pool}", vm)
-
-          subject._check_ready_vm(vm, pool, ttl, provider)
-        end
-
-        it 'should move the VM to the completed queue in Redis' do
-          expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(true)
-          expect(redis.sismember("vmpooler__completed__#{pool}", vm)).to be(false)
-          subject._check_ready_vm(vm, pool, ttl, provider)
-          expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(false)
-          expect(redis.sismember("vmpooler__completed__#{pool}", vm)).to be(true)
-        end
-
-        it 'should log messages about being misnamed' do
-          expect(logger).to receive(:log).with('d', "[!] [#{pool}] '#{vm}' has mismatched hostname, removed from 'ready' queue")
-
-          subject._check_ready_vm(vm, pool, ttl, provider)
-        end
-      end
-
-      context 'is turned on, with correct name and is not ready' do
+      context 'has correct name and is not ready' do
         before(:each) do
           expect(provider).to receive(:vm_ready?).with(pool, vm).and_return(false)
         end
@@ -407,13 +310,13 @@ EOT
         it 'should move the VM to the completed queue' do
           expect(redis).to receive(:smove).with("vmpooler__ready__#{pool}", "vmpooler__completed__#{pool}", vm)
 
-          subject._check_ready_vm(vm, pool, ttl, provider)
+          subject._check_ready_vm(vm, poolconfig, ttl, provider)
         end
 
         it 'should move the VM to the completed queue in Redis' do
           expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(true)
           expect(redis.sismember("vmpooler__completed__#{pool}", vm)).to be(false)
-          subject._check_ready_vm(vm, pool, ttl, provider)
+          subject._check_ready_vm(vm, poolconfig, ttl, provider)
           expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(false)
           expect(redis.sismember("vmpooler__completed__#{pool}", vm)).to be(true)
         end
@@ -421,7 +324,72 @@ EOT
         it 'should log messages about being unreachable' do
           expect(logger).to receive(:log).with('d', "[!] [#{pool}] '#{vm}' is unreachable, removed from 'ready' queue")
 
-          subject._check_ready_vm(vm, pool, ttl, provider)
+          subject._check_ready_vm(vm, poolconfig, ttl, provider)
+        end
+      end
+
+      context 'with hostname mismatch checking enabled' do
+
+        context 'when less than 60 seconds since a VM moved to ready' do
+          before(:each) do
+            redis.hset("vmpooler__vm__#{vm}", 'ready', Time.now)
+          end
+
+          it 'should return nil' do
+            expect(subject._check_ready_vm(vm, poolconfig, ttl, provider)).to be_nil
+          end
+        end
+
+        context 'with a hostname mismatch' do
+          let(:different_hostname) { 'different_name' }
+          before(:each) do
+            expect(provider).to receive(:get_vm).with(pool,vm).and_return(host)
+            host['hostname'] = different_hostname
+          end
+
+          it 'should move the VM to the completed queue' do
+            expect(redis).to receive(:smove).with("vmpooler__ready__#{pool}", "vmpooler__completed__#{pool}", vm)
+
+            subject._check_ready_vm(vm, poolconfig, ttl, provider)
+          end
+
+          it 'should move the VM to the completed queue in Redis' do
+            expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(true)
+            expect(redis.sismember("vmpooler__completed__#{pool}", vm)).to be(false)
+            subject._check_ready_vm(vm, poolconfig, ttl, provider)
+            expect(redis.sismember("vmpooler__ready__#{pool}", vm)).to be(false)
+            expect(redis.sismember("vmpooler__completed__#{pool}", vm)).to be(true)
+          end
+
+          it 'should log messages about being misnamed' do
+            expect(logger).to receive(:log).with('d', "[!] [#{pool}] '#{vm}' has mismatched hostname #{different_hostname}, removed from 'ready' queue")
+
+            subject._check_ready_vm(vm, poolconfig, ttl, provider)
+          end
+        end
+      end
+
+      context 'with hostname mismatch checking disabled on the pool' do
+        before(:each) do
+          config[:pools][0]['check_hostname_for_mismatch'] = false
+        end
+
+        it 'should not run get_vm' do
+          expect(provider).to_not receive(:get_vm)
+
+          subject._check_ready_vm(vm, poolconfig, ttl, provider)
+        end
+      end
+
+      context 'with hostname mismatch checking disabled in config' do
+        before(:each) do
+          config[:config]['check_ready_vm_hostname_for_mismatch'] = false
+        end
+
+        it 'should not run get_vm' do
+          expect(provider).to_not receive(:get_vm)
+
+          subject._check_ready_vm(vm, poolconfig, ttl, provider)
         end
       end
     end
@@ -435,7 +403,7 @@ EOT
       it 'should return' do
         expect(subject).to receive(:vm_mutex).and_return(mutex)
 
-        expect(subject._check_ready_vm(vm, pool, ttl, provider)).to be_nil
+        expect(subject._check_ready_vm(vm, poolconfig, ttl, provider)).to be_nil
       end
     end
   end
@@ -472,32 +440,24 @@ EOT
       allow(provider).to receive(:get_vm).with(pool,vm).and_return(host)
     end
 
-    it 'does nothing with a missing VM' do
+    it 'moves a missing VM to the completed queue' do
+      expect(provider).to receive(:vm_ready?).and_return(false)
       expect(provider).to receive(:get_vm).with(pool,vm).and_return(nil)
       expect(redis.sismember("vmpooler__running__#{pool}", vm)).to be(true)
       subject._check_running_vm(vm, pool, timeout, provider)
-      expect(redis.sismember("vmpooler__running__#{pool}", vm)).to be(true)
+      expect(redis.sismember("vmpooler__running__#{pool}", vm)).to be(false)
     end
 
     context 'valid host' do
-     it 'should not move VM when not poweredOn' do
-        # I'm not sure this test is useful.  There is no codepath
-        # in _check_running_vm that looks at Power State
-        host['powerstate'] = 'PoweredOff'
-
-        expect(logger).not_to receive(:log).with('d', "[!] [#{pool}] '#{vm}' appears to be powered off or dead")
-        expect(redis.sismember("vmpooler__running__#{pool}", vm)).to be(true)
-        subject._check_running_vm(vm, pool, timeout, provider)
-        expect(redis.sismember("vmpooler__running__#{pool}", vm)).to be(true)
-      end
-
       it 'should not move VM if it has no checkout time' do
+        expect(provider).to receive(:vm_ready?).and_return(true)
         expect(redis.sismember("vmpooler__running__#{pool}", vm)).to be(true)
         subject._check_running_vm(vm, pool, 0, provider)
         expect(redis.sismember("vmpooler__running__#{pool}", vm)).to be(true)
       end
 
       it 'should not move VM if TTL is zero' do
+        expect(provider).to receive(:vm_ready?).and_return(true)
         redis.hset("vmpooler__active__#{pool}", vm,(Time.now - timeout*60*60).to_s)
         expect(redis.sismember("vmpooler__running__#{pool}", vm)).to be(true)
         subject._check_running_vm(vm, pool, 0, provider)
@@ -2943,6 +2903,7 @@ EOT
     end
 
     context 'Ready VM in the inventory' do
+      let(:poolconfig) { config[:pools][0] }
       before(:each) do
         expect(provider).to receive(:vms_in_pool).with(pool).and_return(vm_response)
         allow(subject).to receive(:check_ready_vm)
@@ -2966,13 +2927,13 @@ EOT
         big_lifetime = 2000
 
         config[:pools][0]['ready_ttl'] = big_lifetime
-        expect(subject).to receive(:check_ready_vm).with(vm,pool,big_lifetime,provider)
+        expect(subject).to receive(:check_ready_vm).with(vm,poolconfig,big_lifetime,provider)
 
         subject._check_pool(pool_object,provider)
       end
 
       it 'should use a pool TTL of zero if none set' do
-        expect(subject).to receive(:check_ready_vm).with(vm,pool,0,provider)
+        expect(subject).to receive(:check_ready_vm).with(vm,poolconfig,0,provider)
 
         subject._check_pool(pool_object,provider)
       end