[PATCH v3 06/11] vm_boot_test: Improve QEMU images checking

[Anton Mikanovich <amikan@ilbers.de>]

Makes QEMU start test to analyze boot log in real-time. It helps test
cases to finish as soon as booting succeeds and do not wasting time on
waiting.
Get rid of python-subprocess32 backport package.

Signed-off-by: Anton Mikanovich <amikan@ilbers.de>
---
 testsuite/vm_boot_test/vm_boot_test.py | 59 ++++++++++++++++++++------
 1 file changed, 47 insertions(+), 12 deletions(-)

diff --git a/testsuite/vm_boot_test/vm_boot_test.py b/testsuite/vm_boot_test/vm_boot_test.py
index 73fee3e..4c1b6fe 100644
--- a/testsuite/vm_boot_test/vm_boot_test.py
+++ b/testsuite/vm_boot_test/vm_boot_test.py
@@ -1,7 +1,8 @@
 #!/usr/bin/env python3
 
 import os
-import subprocess32
+import select
+import subprocess
 import sys
 import time
 import tempfile
@@ -13,6 +14,9 @@ import start_vm
 
 from avocado import Test
 
+class CanBeFinished(Exception):
+    pass
+
 class VmBase(Test):
 
     def vm_start(self, arch='amd64', distro='buster'):
@@ -31,23 +35,54 @@ class VmBase(Test):
         cmdline = start_vm.format_qemu_cmdline(arch, build_dir, distro,
                                                None, None)
         cmdline.insert(1, '-nographic')
+        cmdline.append('-chardev')
+        cmdline.append('stdio,id=ch0,logfile=' + output_file)
         cmdline.append('-serial')
-        cmdline.append('file:' + output_file)
+        cmdline.append('chardev:ch0')
+        cmdline.append('-monitor')
+        cmdline.append('none')
 
         self.log.info('QEMU boot line: ' + str(cmdline))
 
-        devnull = open(os.devnull, 'w')
-
-        p1 = subprocess32.Popen(cmdline, stdout=devnull, stderr=devnull)
-        time.sleep(int(time_to_wait))
-        p1.kill()
-        p1.wait()
+        login_prompt = b'isar login:'
+        service_prompt = b'Just an example'
+
+        timeout = time.time() + int(time_to_wait)
+
+        p1 = subprocess.Popen(cmdline, stdout=subprocess.PIPE,
+                              stderr=subprocess.PIPE)
+        try:
+            poller = select.poll()
+            poller.register(p1.stdout, select.POLLIN)
+            poller.register(p1.stderr, select.POLLIN)
+            while time.time() < timeout and p1.poll() is None:
+                events = poller.poll(1000 * (timeout - time.time()))
+                for fd, event in events:
+                    if fd == p1.stdout.fileno():
+                        # Wait for the complete string if it is read in chunks
+                        # like "i", "sar", " login:"
+                        time.sleep(0.01)
+                        data = os.read(fd, 1024)
+                        if login_prompt in data:
+                            raise CanBeFinished
+                    if fd == p1.stderr.fileno():
+                        self.log.error(p1.stderr.readline())
+        except CanBeFinished:
+            self.log.debug('Got login prompt')
+        finally:
+            if p1.poll() is None:
+                p1.kill()
+            p1.wait()
 
         if os.path.exists(output_file):
-            if 'isar login:' in open(output_file).read():
-                return
-
-        self.fail('Test failed')
+            with open(output_file, "rb") as f1:
+                data = f1.read()
+                if service_prompt in data and login_prompt in data:
+                    return
+                else:
+                    self.log.error(data)
+
+        self.fail('Log ' + output_file)
 
 class VmBootTestFast(VmBase):
 
-- 
2.25.1