From c6020e922cacd7464772ba85973821398904610d Mon Sep 17 00:00:00 2001
From: "kirby@puppetlabs.com" <mk.kirby@gmail.com>
Date: Mon, 2 Jul 2018 14:24:43 -0700
Subject: [PATCH] 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   | 13 ++++++++++++-
 spec/unit/pool_manager_spec.rb | 19 ++++++++++++++-----
 2 files changed, 26 insertions(+), 6 deletions(-)

diff --git a/lib/vmpooler/pool_manager.rb b/lib/vmpooler/pool_manager.rb
index b3a69c7..e7159ae 100644
--- a/lib/vmpooler/pool_manager.rb
+++ b/lib/vmpooler/pool_manager.rb
@@ -87,6 +87,7 @@ module Vmpooler
 
       $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)
 
       # last boot time is displayed in API, and used by alarming script
       $redis.hset('vmpooler__lastboot', pool, Time.now)
@@ -145,6 +146,16 @@ module Vmpooler
       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']
@@ -152,7 +163,7 @@ module Vmpooler
       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, removed from 'ready' queue")
+      $logger.log('d', "[!] [#{pool['name']}] '#{vm}' has mismatched hostname #{hostname}, removed from 'ready' queue")
       return true
     end
 
diff --git a/spec/unit/pool_manager_spec.rb b/spec/unit/pool_manager_spec.rb
index cf8f82b..959e838 100644
--- a/spec/unit/pool_manager_spec.rb
+++ b/spec/unit/pool_manager_spec.rb
@@ -197,7 +197,7 @@ EOT
         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
 
 
@@ -329,13 +329,22 @@ EOT
       end
 
       context 'with hostname mismatch checking enabled' do
-        before(:each) do
-          expect(provider).to receive(:get_vm).with(pool,vm).and_return(host)
+
+        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
-            host['hostname'] = 'different_name'
+            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
@@ -353,7 +362,7 @@ EOT
           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")
+            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