bin/virtualization: quiet urllib3 info log messages; script now properly polls VM output for success message LP: #1628264

1 files changed, 35 insertions, 22 deletions

diff --git a/bin/virtualization b/bin/virtualization
index 46cf13e..df04470 100755
--- a/bin/virtualization
+++ b/bin/virtualization
@@ -440,6 +440,12 @@ final_message: CERTIFICATION BOOT COMPLETE
 except CalledProcessError as exception:
 logging.exception("Cloud data disk creation failed")
 
+ def log_check(self,stream):
+ if "CERTIFICATION BOOT COMPLETE" in stream:
+ return 0
+ else:
+ return 1
+
 def start(self):
 if self.arch == 'arm64':
 # lp:1548539 - For arm64, we need to make sure we're using qemu
@@ -485,36 +491,42 @@ final_message: CERTIFICATION BOOT COMPLETE
 # Boot Virtual Machine
 instance = self.boot_image(self.image)
 
- time.sleep(self.timeout)
 # If running in console, reset console window to regain
 # control from VM Serial I/0
 if sys.stdout.isatty():
 call('reset')
 # Check to be sure VM boot was successful
- with open(self.debug_file, 'r') as debug_file:
- file_contents = debug_file.read()
- if "CERTIFICATION BOOT COMPLETE" in file_contents:
- if "END SSH HOST KEY KEYS" in file_contents:
- print("Booted successfully", file=sys.stderr)
+ self.elapsed_time=0
+ status = 1
+ while self.elapsed_time <= self.timeout:
+ # Check log every 30 seconds to see if the VM boots
+ with open(self.debug_file, 'r') as debug_file:
+ status = self.log_check(debug_file.read())
+ if status == 0:
+ logging.info("Booted successfully.")
+ break
 else:
- print("Booted successfully (Previously "
- "initalized VM)", file=sys.stderr)
- status = 0
- else:
- print("E: KVM instance failed to boot",
- file=sys.stderr)
- print("Console output".center(72, "="),
- file=sys.stderr)
- with open(self.debug_file, 'r') as console_log:
- print(console_log.read(), file=sys.stderr)
- print("E: KVM instance failed to boot",
- file=sys.stderr)
+ # Sleep 30 seconds and log check again
+ time.sleep(30)
+ self.elapsed_time += 30
+ else:
+ # Finally, if we didn't get the Success message by now try
+ # one more time and return 1 if we still haven't booted
+ if status != 0:
+ with open(self.debug_file, 'r') as debug_file:
+ stream = debug_file.read()
+ status = self.log_check(stream)
+ if status == 0:
+ logging.info("Booted successfully.")
+ else:
+ logging.error("KVM instance failed to boot.")
+ logging.error("Console output".center(72, "="))
+ logging.error(stream)
 self.process.terminate()
 elif not self.image:
- print("Could not find downloaded image")
+ logging.error("Could not find downloaded image")
 else:
- print("Could not find: {}".format(self.image),
- file=sys.stderr)
+ logging.error("Could not find: {}".format(self.image))
 
 return status
 
@@ -735,7 +747,7 @@ def test_lxd(args):
 
 
 def test_kvm(args):
- print("Executing KVM Test", file=sys.stderr)
+ logging.debug("Executing KVM Test")
 
 image = ""
 timeout = ""
@@ -809,6 +821,7 @@ def main():
 
 # silence normal output from requests module
 logging.getLogger("requests").setLevel(logging.WARNING)
+ logging.getLogger("urllib3").setLevel(logging.WARNING)
 
 # Verify args
 try: