From 19ee2cc0ca0b5ff3021594c432e5ad7d5f9433f4 Mon Sep 17 00:00:00 2001
From: Kunal Mehta <legoktm@debian.org>
Date: Mon, 17 Jun 2024 18:35:07 -0400
Subject: [PATCH] Actually test that logs are flowing to sd-log

Instead of checking that a folder exists, we now trigger a log entry
in all VMs and then look for that log entry in the logs.

We also verify that sd-gpg, sd-log and sd-whonix logs are *not* flowing.
---
 tests/base.py        |  1 +
 tests/test_log_vm.py | 47 +++++++++++++++++++++++++++++++++-----------
 2 files changed, 37 insertions(+), 11 deletions(-)

diff --git a/tests/base.py b/tests/base.py
index 9d6309d6..a15c7e6c 100644
--- a/tests/base.py
+++ b/tests/base.py
@@ -19,6 +19,7 @@
 CURRENT_FEDORA_TEMPLATE = "fedora-" + CURRENT_FEDORA_VERSION + "-xfce"
 CURRENT_FEDORA_DVM = "fedora-" + CURRENT_FEDORA_VERSION + "-dvm"
 CURRENT_WHONIX_VERSION = "17"
+CURRENT_DEBIAN_VERSION = "bookworm"
 
 
 # Lifted from launcher/sdw_util/Util.py
diff --git a/tests/test_log_vm.py b/tests/test_log_vm.py
index df9dc317..4ee847ff 100644
--- a/tests/test_log_vm.py
+++ b/tests/test_log_vm.py
@@ -1,6 +1,9 @@
+import secrets
+import string
+import subprocess
 import unittest
 
-from base import SD_VM_Local_Test
+from base import CURRENT_DEBIAN_VERSION, SD_VM_Local_Test
 
 
 class SD_Log_Tests(SD_VM_Local_Test):
@@ -29,18 +32,40 @@ def test_redis_service_running(self):
         self.assertTrue(self._service_is_active("redis"))
 
     def test_logs_are_flowing(self):
-        cmd_output = self._run("ls -1 /home/user/QubesIncomingLogs")
-        log_dirs = cmd_output.split("\n")
-        # Confirm AppVMs are sending logs
-        self.assertIn("sd-app", log_dirs)
-        # The following will only have logs if the machine has booted,
-        # which is not guaranteed given that we randomize test order.
-        # self.assertIn("sd-devices", log_dirs)
-        # self.assertIn("sd-proxy", log_dirs)
-        # self.assertIn("sd-viewer", log_dirs)
+        """
+        To test that logs work, we run a unique command in each VM we care
+        about that gets logged, and then check for that string in the logs.
+        """
+        # Random string, to avoid collisions with other test runs
+        token = "".join(secrets.choice(string.ascii_uppercase) for _ in range(10))
+
+        # All @tag:sd-workstation VMs
+        all_vms = [vm.name for vm in self.app.domains if "sd-workstation" in vm.tags]
+        # base template doesn't have sd-log configured
+        # TODO: test a sd-viewer based dispVM
+        skip = [f"sd-base-{CURRENT_DEBIAN_VERSION}-template", "sd-viewer"]
+        # VMs we expect logs will not go to
+        no_log_vms = ["sd-gpg", "sd-log", "sd-whonix"]
+
+        # We first run the command in each VM, and then do a second loop to
+        # look for the token in the log entry, so there's enough time for the
+        # log entry to get written.
+        for vm_name in all_vms:
+            if vm_name in skip:
+                continue
+            # The sudo call will make it into syslog
+            subprocess.check_call(["qvm-run", vm_name, f"sudo echo {token}"])
+
+        for vm_name in all_vms:
+            if vm_name in skip:
+                continue
+            syslog = f"/home/user/QubesIncomingLogs/{vm_name}/syslog.log"
+            if vm_name in no_log_vms:
+                self.assertFalse(self._fileExists(syslog))
+            else:
+                self.assertIn(token, self._get_file_contents(syslog))
 
     def test_log_dirs_properly_named(self):
-        # Rerunning this command to keep test output readable
         cmd_output = self._run("ls -1 /home/user/QubesIncomingLogs")
         log_dirs = cmd_output.split("\n")
         # Confirm we don't have 'host' entries from Whonix VMs