Archive and compare iterations.log for implicit coupling

changelog-entries/743.md

@@ -0,0 +1 @@
+- Archived `precice-*-iterations.log` files into `iterations-logs/` during system tests and compared them against reference copies for implicit-coupling regression checks ([#743](https://github.com/precice/tutorials/pull/743)).

tools/tests/README.md

@@ -107,6 +107,8 @@ The easiest way to debug a systemtest run is first to have a look at the output
 If this does not provide enough hints, the next step is to download the generated `system_tests_run_<run_id>_<run_attempt>` artifact. Note that by default this will only be generated if the systemtests fail.
 Inside the archive, a test-specific subfolder like `flow-over-heated-plate_fluid-openfoam-solid-fenics_2023-11-19-211723` contains two log files: `system-tests-stderr.log` and `system-tests-stdout.log`. This can be a starting point for a further investigation. When fieldcompare runs with `--diff`, it writes VTK diff files under `precice-exports/`; if the comparison fails, those files are copied into a `diff-results/` subfolder in the same run directory (mirroring any subpaths under `precice-exports/`) so you can open them (e.g. in ParaView) to see where results differ from the reference. On successful comparisons, `diff-results/` is therefore absent.
 
+For implicit-coupling runs, `precice-*-iterations.log` files are collected into `iterations-logs/` and compared by hash against archived reference copies (stored next to each reference `.tar.gz` in a `*.iterations-logs/` directory, or legacy `.iterations-hashes.json` sidecars). A mismatch fails the test.
+
 ## Adding new tests
 
 ### Adding tutorials

tools/tests/generate_reference_results.py

@@ -5,6 +5,7 @@
 from systemtests.Systemtest import Systemtest, GLOBAL_TIMEOUT
 from pathlib import Path
 from typing import List
+import shutil
 from paths import PRECICE_TESTS_DIR, PRECICE_TUTORIAL_DIR
 import hashlib
 from jinja2 import Environment, FileSystemLoader
@@ -179,6 +180,20 @@ def main():
             raise RuntimeError(
                 f"Error executing: \n {systemtest} \n Could not find result folder {reference_result_folder}\n Probably the tutorial did not run through properly. Please check corresponding logs")
 
+        collected = systemtest._collect_iterations_logs(systemtest.get_system_test_dir())
+        if collected:
+            ref_logs_dir = systemtest._iterations_logs_reference_dir()
+            ref_logs_dir.mkdir(parents=True, exist_ok=True)
+            for rel, src in collected:
+                dest = ref_logs_dir / rel
+                dest.parent.mkdir(parents=True, exist_ok=True)
+                shutil.copy2(src, dest)
+            logging.info(
+                "Wrote iterations logs for %s to %s",
+                systemtest.reference_result.path.name,
+                ref_logs_dir,
+            )
+
     # write readme
     for tutorial in reference_result_per_tutorial.keys():
         reference_results_dir = tutorial.path / "reference-results"

tools/tests/systemtests/Systemtest.py

@@ -1,3 +1,5 @@
+import hashlib
+import json
 import subprocess
 from typing import List, Dict, Optional, Tuple
 from jinja2 import Environment, FileSystemLoader
@@ -23,6 +25,7 @@
 SHORT_TIMEOUT = 10
 
 DIFF_RESULTS_DIR = "diff-results"
+ITERATIONS_LOGS_DIR = "iterations-logs"
 
 
 def slugify(value, allow_unicode=False):
@@ -491,6 +494,119 @@ def __archive_fieldcompare_diffs(self) -> None:
                 self,
             )
 
+    @staticmethod
+    def _sha256_file(path: Path) -> str:
+        """Compute SHA-256 hex digest of a file."""
+        h = hashlib.sha256()
+        mv = memoryview(bytearray(128 * 1024))
+        with open(path, 'rb', buffering=0) as f:
+            while n := f.readinto(mv):
+                h.update(mv[:n])
+        return h.hexdigest()
+
+    def _iterations_logs_reference_dir(self) -> Path:
+        """Directory next to the reference tar storing archived iterations.log files."""
+        stem = self.reference_result.path.name.replace(".tar.gz", "")
+        return self.reference_result.path.parent / f"{stem}.iterations-logs"
+
+    def _collect_iterations_logs(
+        self, system_test_dir: Path
+    ) -> List[Tuple[str, Path]]:
+        """
+        Collect precice-*-iterations.log files from case dirs.
+        Returns list of (relative_path, absolute_path) e.g. ("solid-fenics/precice-Solid-iterations.log", path).
+        """
+        collected = []
+        for case in self.case_combination.cases:
+            case_dir = system_test_dir / Path(case.path).name
+            if not case_dir.exists():
+                continue
+            for log_file in case_dir.glob("precice-*-iterations.log"):
+                if log_file.is_file():
+                    rel = f"{Path(case.path).name}/{log_file.name}"
+                    collected.append((rel, log_file))
+        return collected
+
+    def _reference_iterations_hashes(self) -> Optional[Dict[str, str]]:
+        """
+        Load expected iterations.log hashes from archived reference files or a legacy sidecar.
+        Returns None if no reference data is available.
+        """
+        ref_dir = self._iterations_logs_reference_dir()
+        if ref_dir.is_dir():
+            ref_hashes = {}
+            for log_file in ref_dir.rglob("precice-*-iterations.log"):
+                if log_file.is_file():
+                    rel = log_file.relative_to(ref_dir).as_posix()
+                    ref_hashes[rel] = self._sha256_file(log_file)
+            if ref_hashes:
+                return ref_hashes
+
+        sidecar = self.reference_result.path.with_suffix(".iterations-hashes.json")
+        if not sidecar.exists():
+            return None
+        try:
+            ref_hashes = json.loads(sidecar.read_text())
+        except (json.JSONDecodeError, OSError) as e:
+            logging.warning(
+                "Could not read iterations hashes from %s: %s", sidecar, e
+            )
+            return None
+        return ref_hashes if ref_hashes else None
+
+    def __archive_iterations_logs(self) -> None:
+        """Copy precice-*-iterations.log from case dirs into iterations-logs/ for CI artifacts."""
+        collected = self._collect_iterations_logs(self.system_test_dir)
+        if not collected:
+            return
+        dest_dir = self.system_test_dir / ITERATIONS_LOGS_DIR
+        dest_dir.mkdir(exist_ok=True)
+        for rel, src in collected:
+            dest_name = Path(rel).name
+            if len(collected) > 1:
+                prefix = Path(rel).parent.name + "_"
+                dest_name = prefix + dest_name
+            shutil.copy2(src, dest_dir / dest_name)
+        logging.debug(
+            "Archived %d iterations log(s) to %s for %s",
+            len(collected),
+            dest_dir,
+            self,
+        )
+
+    def __compare_iterations_hashes(self) -> bool:
+        """
+        Compare current iterations.log hashes against reference data.
+        Returns True if comparison passes (or is skipped). Returns False if hashes differ.
+        """
+        ref_hashes = self._reference_iterations_hashes()
+        if ref_hashes is None:
+            return True
+        collected = self._collect_iterations_logs(self.system_test_dir)
+        current = {rel: self._sha256_file(p) for rel, p in collected}
+        for rel, expected in ref_hashes.items():
+            if rel not in current:
+                logging.critical(
+                    "Missing iterations log %s (expected from reference); %s fails",
+                    rel,
+                    self,
+                )
+                return False
+            if current[rel] != expected:
+                logging.critical(
+                    "Hash mismatch for %s (iterations.log regression); %s fails",
+                    rel,
+                    self,
+                )
+                return False
+        if len(current) != len(ref_hashes):
+            extra = set(current) - set(ref_hashes)
+            logging.critical(
+                "Unexpected iterations log(s) %s; %s fails", extra, self
+            )
+            return False
+        return True
+
     def _build_docker(self):
         """
         Builds the docker image
@@ -664,6 +780,21 @@ def run(self, run_directory: Path):
                 solver_time=docker_run_result.runtime,
                 fieldcompare_time=0)
 
+        self.__archive_iterations_logs()
+        if not self.__compare_iterations_hashes():
+            self.__write_logs(std_out, std_err)
+            logging.critical(
+                f"Iterations.log hash comparison failed (regression), {self} failed"
+            )
+            return SystemtestResult(
+                False,
+                std_out,
+                std_err,
+                self,
+                build_time=docker_build_result.runtime,
+                solver_time=docker_run_result.runtime,
+                fieldcompare_time=0)
+
         fieldcompare_result = self._run_field_compare()
         std_out.extend(fieldcompare_result.stdout_data)
         std_err.extend(fieldcompare_result.stderr_data)