Capture redacted guest serial while waiting for shutdown

dev/iso-smoke.py

@@ -575,10 +575,35 @@ class VM:
             raise
 
     def wait_poweroff(self, timeout):
-        try:
+        deadline = time.monotonic() + timeout
-            rc = self.process.wait(timeout=timeout)
+        serial_open = True
-        except subprocess.TimeoutExpired as exc:
+        while self.process.poll() is None:
-            raise SmokeError('Guest failed to power off in time') from exc
+            remaining = deadline - time.monotonic()
+            if remaining <= 0:
+                raise SmokeError('Guest failed to power off in time')
+            if serial_open:
+                try:
+                    self.console.read(min(remaining, 0.25))
+                except SmokeError as exc:
+                    if str(exc) != 'Guest console closed':
+                        raise
+                    serial_open = False
+            else:
+                try:
+                    self.process.wait(timeout=remaining)
+                except subprocess.TimeoutExpired as exc:
+                    raise SmokeError('Guest failed to power off in time') from exc
+        # Capture bytes queued immediately before exit, even if poll observed
+        # the child exiting before the first serial read.
+        while serial_open:
+            try:
+                if not self.console.read(0):
+                    break
+            except SmokeError as exc:
+                if str(exc) != 'Guest console closed':
+                    raise
+                serial_open = False
+        rc = self.process.returncode
         if rc:
             raise SmokeError(f'Test QEMU failed during poweroff ({rc})')
 

tests/test_iso_smoke.py

@@ -4,6 +4,8 @@ from pathlib import Path
 import socket
 import select
 import subprocess
+import sys
+import time
 import tempfile
 import threading
 import unittest
@@ -182,6 +184,46 @@ class SmokeTests(unittest.TestCase):
         with self.assertRaisesRegex(self.mod.SmokeError, 'Installer.*status 1'):
             console.finish_installer('testtoken', timeout=0.05)
 
+    def shutdown_vm(self, program):
+        one, two = socket.socketpair()
+        vm = self.mod.VM.__new__(self.mod.VM)
+        vm.console = self.mod.Console(one, self.root / 'shutdown.log', ['split-secret'])
+        self.addCleanup(vm.console.close)
+        code = ('import socket,sys,time; s=socket.socket(fileno=int(sys.argv[1])); ' + program)
+        vm.process = subprocess.Popen([sys.executable, '-c', code, str(two.fileno())],
+                                      pass_fds=(two.fileno(),), stdin=subprocess.DEVNULL)
+        two.close()
+        def reap():
+            if vm.process.poll() is None:
+                vm.process.terminate()
+            vm.process.wait(timeout=2)
+        self.addCleanup(reap)
+        return vm
+
+    def test_poweroff_drains_and_redacts_serial_until_owned_process_exits(self):
+        vm = self.shutdown_vm("s.sendall(b'Stopping split-'); time.sleep(.02); "
+                              "s.sendall(b'secret service\\nPower down\\n'); s.close()")
+        vm.wait_poweroff(1)
+        output = (self.root / 'shutdown.log').read_bytes()
+        self.assertIn(b'Stopping [REDACTED] service\nPower down\n', output)
+        self.assertNotIn(b'split-secret', output)
+
+    def test_poweroff_preserves_failure_cause_and_original_timeout(self):
+        for program, error in (("s.sendall(b'Stop job stuck\\n'); s.close(); time.sleep(1)",
+                                'Guest failed to power off in time'),
+                               ("s.sendall(b'QEMU shutdown failed\\n'); s.close(); sys.exit(7)",
+                                'Test QEMU failed during poweroff')):
+            with self.subTest(program=program):
+                vm = self.shutdown_vm(program)
+                started = time.monotonic()
+                with self.assertRaisesRegex(self.mod.SmokeError, error):
+                    vm.wait_poweroff(.15)
+                self.assertLess(time.monotonic() - started, .5)
+                output = (self.root / 'shutdown.log').read_bytes()
+                self.assertIn(b'Stop job stuck' if 'time.sleep' in program else b'QEMU shutdown failed', output)
+                if 'time.sleep' in program:
+                    self.assertIsNone(vm.process.poll(), 'timeout must not kill or falsely pass the owned process')
+
     def test_frame_real_shell_roundtrip_does_not_accept_sentinel_in_echo(self):
         one, two = socket.socketpair()
         self.addCleanup(one.close)