fix(console): a serial console reports its VM's stop

When a VM stopped, its console's stream could end before the worker's
next check saw the VM shut off. The check then found no stream to drop and
said nothing, or, seeing the VM still running, opened the console again,
which libvirt refused, and the session ended. The worker now remembers
whether the VM ran at its last check, and a console that cannot be opened
again because the VM stopped meanwhile is a stop: the terminal says the VM
is not running and the console opens again when it starts. A new stream is
the console's before its callback is registered, which may end it at once.

The live serial test's VM now repeats its BIOS banner (it reboots right
after finding no boot disk), so a console attached late still gets one,
and the test waits for the superuser's console to show it before the VM
stops. A run of the whole live suite over the socket missed the banner of
the paused-then-resumed VM before.

conf/daemon/consolecallback

@@ -47,19 +47,28 @@ class Console:
         self.domain = connection.lookupByUUIDString(uuid)
         self.connection = connection
         self.stream = None
+        self.active = False  # the VM ran at the last check
         self.running = True
 
     def check(self):
-        """Open the stream while the VM runs, drop it while it does not."""
+        """Open the stream while the VM runs, drop it while it does not. The
+        stream may have ended first: the VM's stop is still reported."""
         active = self.domain.state()[0] in (libvirt.VIR_DOMAIN_RUNNING, libvirt.VIR_DOMAIN_PAUSED)
         if active and self.stream is None:
             stream = self.connection.newStream(libvirt.VIR_STREAM_NONBLOCK)
-            self.domain.openConsole(None, stream, 0)  # a console in use is refused
-            stream.eventAddCallback(libvirt.VIR_STREAM_EVENT_READABLE, from_vm, self)
-            self.stream = stream
-        elif not active and self.stream is not None:
+            try:
+                self.domain.openConsole(None, stream, 0)  # a console in use is refused
+            except libvirt.libvirtError:
+                if self.domain.isActive():
+                    raise
+                active = False  # it stopped meanwhile
+            else:
+                self.stream = stream  # first: the callback may end it at once
+                stream.eventAddCallback(libvirt.VIR_STREAM_EVENT_READABLE, from_vm, self)
+        if not active and self.active:
             self.close_stream()
             say("The VM is not running: its console opens again when it starts")
+        self.active = active
 
     def close_stream(self):
         stream, self.stream = self.stream, None

console/tests/test_consolecallback.py

@@ -1,5 +1,6 @@
 """The serial console worker: a paste reaches the VM whole although its
-stream takes it in parts or is busy, and the stream is dropped once."""
+stream takes it in parts or is busy, the stream is dropped once, and a VM
+that stops is reported."""
 
 from importlib.machinery import SourceFileLoader
 from importlib.util import module_from_spec, spec_from_loader
@@ -59,6 +60,30 @@ class ConsoleWorkerTests(TestCase):
         console.close_stream()  # the other thread, a moment later
         stream.abort.assert_called_once_with()
 
+    def test_a_vm_that_stops_is_reported_although_its_stream_ended_first(self):
+        console = self.cb.Console.__new__(self.cb.Console)
+        console.domain = MagicMock()
+        console.stream = None  # from_vm dropped it at the stream's end
+        console.active = True
+        console.domain.state.return_value = [self.cb.libvirt.VIR_DOMAIN_SHUTOFF]
+        with patch.object(self.cb, "say") as say:
+            console.check()
+            console.check()
+        say.assert_called_once_with("The VM is not running: its console opens again when it starts")
+
+    def test_a_vm_that_stops_while_its_console_reopens_is_reported(self):
+        console = self.cb.Console.__new__(self.cb.Console)
+        console.domain, console.connection = MagicMock(), MagicMock()
+        console.stream = None
+        console.active = True
+        console.domain.state.return_value = [self.cb.libvirt.VIR_DOMAIN_RUNNING]
+        console.domain.openConsole.side_effect = self.cb.libvirt.libvirtError("domain is not running")
+        console.domain.isActive.return_value = 0
+        with patch.object(self.cb, "say") as say:
+            console.check()
+        say.assert_called_once_with("The VM is not running: its console opens again when it starts")
+        self.assertIsNone(console.stream)
+
     def test_a_closed_client_ends_the_worker(self):
         with patch.object(self.cb.os, "read", return_value=b""):
             self.cb.from_client(None, 0, None, self.console)

console/tests/test_live_serial.py

@@ -1,14 +1,13 @@
 """Live serial console: socketiod opens a running wvc-test VM's console on the
 TCP host (TEST_LIBVIRT_HOST, with its password) and on the SSH host
 (TEST_LIBVIRT_SSH_HOST). The VM has no graphics and no OS; SeaBIOS writes its
-banner to the serial port. Runs only with TEST_LIBVIRT_HOST set."""
+banner to the serial port, again on each reboot after it finds no boot disk.
+Runs only with TEST_LIBVIRT_HOST set."""
 
 import os
 import time
 import unittest
 
-import libvirt
-
 from django.contrib.auth import get_user_model
 from django.test import TransactionTestCase
 from vrtManager.connection import connection_manager
@@ -30,13 +29,14 @@ def wait_for(condition, seconds=30):
 
 
 def serial_vm(conn, name):
-    """A paused VM without graphics whose BIOS writes to the serial console once resumed."""
+    """A running VM without graphics whose BIOS writes to the serial console in a loop:
+    a console opened late still gets the banner."""
     dom = conn.defineXML(
         f"<domain type='kvm'><name>{name}</name><memory unit='MiB'>64</memory><vcpu>1</vcpu>"
-        "<os><type arch='x86_64' machine='q35'>hvm</type><bios useserial='yes'/></os>"
+        "<os><type arch='x86_64' machine='q35'>hvm</type><bios useserial='yes' rebootTimeout='0'/></os>"
         "<devices><serial type='pty'><target port='0'/></serial><console type='pty'/></devices></domain>"
     )
-    dom.createWithFlags(libvirt.VIR_DOMAIN_START_PAUSED)
+    dom.create()
     return dom
 
 
@@ -73,8 +73,6 @@ class LiveSerialConsoleTestCase(TransactionTestCase):
             with self.subTest(host=args[0], type=args[3]):
                 token, dom = self.token(*args)
                 client, received = console(self.port, token)
-                time.sleep(1)  # the console is open on the paused VM; its BIOS writes once it runs
-                dom.resume()
                 deadline = time.monotonic() + 30
                 while "SeaBIOS" not in "".join(received["output"]) and time.monotonic() < deadline:
                     time.sleep(0.2)
@@ -86,6 +84,9 @@ class LiveSerialConsoleTestCase(TransactionTestCase):
                 wait_for(lambda: received["taken_over"])
                 self.assertEqual(received["taken_over"], ["serial-live-admin"])
                 client.disconnect()
+                # the superuser's console is attached before the VM stops
+                wait_for(lambda: "SeaBIOS" in "".join(admin_received["output"]))
+                self.assertIn("SeaBIOS", "".join(admin_received["output"]))
                 # the VM stops: the terminal says so
                 dom.destroy()
                 wait_for(lambda: "not running" in "".join(admin_received["output"]))