Merge branch 'bschubert/casd-logs' into 'master'

cascache.py: Save casd logs in a file for retrieval

Closes #1156

See merge request BuildStream/buildstream!1616

2 files changed, 83 insertions, 3 deletions

diff --git a/src/buildstream/_cas/cascache.py b/src/buildstream/_cas/cascache.py
index 6315c1f93..43375c635 100644
--- a/src/buildstream/_cas/cascache.py
+++ b/src/buildstream/_cas/cascache.py
@@ -49,6 +49,8 @@ _BUFFER_SIZE = 65536
 # Refresh interval for disk usage of local cache in seconds
 _CACHE_USAGE_REFRESH = 5
 
+_CASD_MAX_LOGFILES = 10
+
 
 # A CASCache manages a CAS repository as specified in the Remote Execution API.
 #
@@ -84,8 +86,13 @@ class CASCache():
                     casd_args.append('--protect-session-blobs')
 
             casd_args.append(path)
-            self._casd_process = subprocess.Popen(casd_args, cwd=path)
+
             self._casd_start_time = time.time()
+            self.casd_logfile = self._rotate_and_get_next_logfile()
+
+            with open(self.casd_logfile, "w") as logfile_fp:
+                self._casd_process = subprocess.Popen(
+                    casd_args, cwd=path, stdout=logfile_fp, stderr=subprocess.STDOUT)
         else:
             self._casd_process = None
 
@@ -662,6 +669,30 @@ class CASCache():
     #             Local Private Methods            #
     ################################################
 
+    # _rotate_and_get_next_logfile()
+    #
+    # Get the logfile to use for casd
+    #
+    # This will ensure that we don't create too many casd log files by
+    # rotating the logs and only keeping _CASD_MAX_LOGFILES logs around.
+    #
+    # Returns:
+    #   (str): the path to the log file to use
+    #
+    def _rotate_and_get_next_logfile(self):
+        log_dir = os.path.join(self.casdir, "logs")
+
+        try:
+            existing_logs = sorted(os.listdir(log_dir))
+        except FileNotFoundError:
+            os.makedirs(log_dir)
+        else:
+            while len(existing_logs) >= _CASD_MAX_LOGFILES:
+                logfile_to_delete = existing_logs.pop(0)
+                os.remove(os.path.join(log_dir, logfile_to_delete))
+
+        return os.path.join(log_dir, str(self._casd_start_time) + ".log")
+
     def _refpath(self, ref):
         return os.path.join(self.casdir, 'refs', 'heads', ref)
 
@@ -946,7 +977,12 @@ class CASCache():
 
             if messenger:
                 messenger.message(
-                    Message(MessageType.BUG, "Buildbox-casd died during the run. Exit code: {}".format(return_code))
+                    Message(
+                        MessageType.BUG,
+                        "Buildbox-casd died during the run. Exit code: {}, Logs: {}".format(
+                            return_code, self.casd_logfile
+                        ),
+                    )
                 )
             return
 
@@ -976,7 +1012,12 @@ class CASCache():
 
         if return_code != 0 and messenger:
             messenger.message(
-                Message(MessageType.BUG, "Buildbox-casd didn't exit cleanly. Exit code: {}".format(return_code))
+                Message(
+                    MessageType.BUG,
+                    "Buildbox-casd didn't exit cleanly. Exit code: {}, Logs: {}".format(
+                        return_code, self.casd_logfile
+                    ),
+                )
             )
 
         self._casd_process = None
diff --git a/tests/internals/cascache.py b/tests/internals/cascache.py
index 8eb5cc29f..81273aeaf 100644
--- a/tests/internals/cascache.py
+++ b/tests/internals/cascache.py
@@ -61,3 +61,42 @@ def test_report_when_cascache_is_forcefully_killed(tmp_path, monkeypatch):
     message = messenger.message.call_args[0][0]
     assert message.message_type == MessageType.WARN
     assert "killed" in message.message
+
+
+def test_casd_redirects_stderr_to_file_and_rotate(tmp_path, monkeypatch):
+    n_max_log_files = 10
+
+    dummy_buildbox_casd = tmp_path.joinpath("buildbox-casd")
+    dummy_buildbox_casd.write_text("#!/bin/bash\necho -e hello")
+    dummy_buildbox_casd.chmod(0o777)
+    monkeypatch.setenv("PATH", str(tmp_path), prepend=os.pathsep)
+
+    casd_files_path = tmp_path.joinpath("casd")
+    casd_logs_path = casd_files_path.joinpath("cas", "logs")
+
+    # Ensure we don't have any files in the log directory
+    assert not casd_logs_path.exists()
+    existing_log_files = []
+
+    # Let's create the first `n_max_log_files` log files
+    for i in range(1, n_max_log_files + 1):
+        cache = CASCache(str(casd_files_path), casd=True)
+        time.sleep(0.05)
+        cache.release_resources()
+
+        existing_log_files = sorted(casd_logs_path.iterdir())
+        assert len(existing_log_files) == i
+        assert existing_log_files[-1].read_text() == "hello\n"
+
+    # Ensure the oldest log files get removed first
+    for _ in range(3):
+        evicted_file = existing_log_files.pop(0)
+
+        cache = CASCache(str(casd_files_path), casd=True)
+        time.sleep(0.05)
+        cache.release_resources()
+
+        existing_log_files = sorted(casd_logs_path.iterdir())
+        assert len(existing_log_files) == n_max_log_files
+        assert evicted_file not in existing_log_files
+        assert existing_log_files[-1].read_text() == "hello\n"