test: cleanup and improve "wait for readiness" checks

In Microvm.spawn(), we try to wait for the firecracker process to
initialize itself and become ready to server requests. We have multiple
checks of varying fidelity in there, and they can be strictly ordered by
this based on what they wait for: e.g. if we wait for SSH availability
(guest userspace is ready), there is no point to _also_ wait for
firecracker's startup message in the logs, as that is always printed
before SSH becomes available. Thus clean this logic up to only do the
one check that has the highest fidelity in any given setup.

While we're at it, update/move some comments.

Then, improve the check for API server readiness to wait for the log
message that signals completion of API server initialization, instead of
just waiting for socket file creation (which happens before we are
actually ready to accept connections on it).

Signed-off-by: Patrick Roy <[email protected]>

Author: roypat

tests/framework/microvm.py

@@ -688,21 +688,33 @@ def spawn(
         if emit_metrics:
             self.monitors.append(FCMetricsMonitor(self))
 
-        # Wait for the jailer to create resources needed, and Firecracker to
-        # create its API socket.
-        # We expect the jailer to start within 80 ms. However, we wait for
-        # 1 sec since we are rechecking the existence of the socket 5 times
-        # and leave 0.2 delay between them.
-        if "no-api" not in self.jailer.extra_args:
-            self._wait_for_api_socket()
+        # Ensure Firecracker is in as good a state as possible wrts guest
+        # responsiveness / API availability.
+        # If we are using a config file and it has a network device specified,
+        # use SSH to wait until guest userspace is available. If we are
+        # using the API, wait until the log message indicating the API server
+        # has finished initializing is printed (if logging is enabled), or
+        # until the API socket file has been created.
+        # If none of these apply, do a last ditch effort to make sure the
+        # Firecracker process itself at least came up by checking
+        # for the startup log message. Otherwise, you're on your own kid.
         if "config-file" in self.jailer.extra_args and self.iface:
             self.wait_for_ssh_up()
-        if self.log_file and log_level in ("Trace", "Debug", "Info"):
+        elif "no-api" not in self.jailer.extra_args:
+            if self.log_file and log_level in ("Trace", "Debug", "Info"):
+                self.check_log_message("API server started.")
+            else:
+                self._wait_for_api_socket()
+        elif self.log_file and log_level in ("Trace", "Debug", "Info"):
             self.check_log_message("Running Firecracker")
 
     @retry(wait=wait_fixed(0.2), stop=stop_after_attempt(5), reraise=True)
     def _wait_for_api_socket(self):
         """Wait until the API socket and chroot folder are available."""
+
+        # We expect the jailer to start within 80 ms. However, we wait for
+        # 1 sec since we are rechecking the existence of the socket 5 times
+        # and leave 0.2 delay between them.
         os.stat(self.jailer.api_socket_path())
 
     @retry(wait=wait_fixed(0.2), stop=stop_after_attempt(5), reraise=True)