rugnux: record in the report how the run was invoked, what it cost and what it ran on

The results report said what the run determined but nothing about how it was
produced, so a report read next to a lost shell history could not be reproduced
or compared. Four keys in the header block, all new, none renamed - a consumer
that greps for what it needs is unaffected, so REPORT_VERSION does not move:

  COMMAND_LINE= rugnux -o myrun --model model.pdb dataset_master.h5
  WALL_TIME= 262.41
  GPU_COUNT= 4
  GPU= 4x NVIDIA A100-SXM4-80GB

The command line is argv as one shell-ready line; an argument that would not
survive being pasted back into a shell is single-quoted, so a file prefix with a
space comes back as the one argument it was. It replaces the raw argv echo at the
top of the run, which had no quoting at all.

WALL_TIME is the whole invocation, timed from the top of the CLI. It is
deliberately not result.total_time_s, which starts inside Rugnux::Run and so
counts neither opening the file nor setting up the analysis - and which --mode
scale never sets at all, having no ProcessResult of its own. It is printed on
stdout as well, next to the processing time it is slightly larger than.

The GPUs are the reason rugnux is fast, and until now nothing said whether any
were being used. get_gpu_names() reports them per device and get_gpu_description()
collapses repeats, so four identical cards read as one line rather than the same
name four times and a mixed machine keeps one group per model. Both have a
CPU-only implementation, so the JFJOCH_USE_CUDA=OFF build reports GPU_COUNT= 0
rather than failing to link.

The same line is printed at startup, before the run rather than after it: a
machine that turns out to have no GPU - a driver mismatch, a CUDA_VISIBLE_DEVICES
left over from another job - is worth knowing about while there is still time to
stop, not once the run has taken an order of magnitude longer than it should.
GPU_COUNT= 0 is written with no GPU= line beside it, because the absence is the
statement.

The header comment claiming timing is deliberately absent from the report is now
wrong and says so: rates and per-image costs stay on stdout, the total does not.

Verified on the rotation test dataset in both build configurations, with and
without CUDA_VISIBLE_DEVICES, in --mode mx and --mode scale.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_016WmryXe8ASbNi632sUMfsa

common/CUDAWrapper.cpp

@@ -1,14 +1,39 @@
 // SPDX-FileCopyrightText: 2024 Filip Leonarski, Paul Scherrer Institute <filip.leonarski@psi.ch>
 // SPDX-License-Identifier: GPL-3.0-only
 
-#ifndef JFJOCH_USE_CUDA
-
 #include "CUDAWrapper.h"
 
+// Build-independent: the CUDA build gets get_gpu_names() from CUDAWrapper.cu, the CPU-only build from
+// the stub below, and this collapses whichever list came back. Four identical cards read better as
+// "4x <name>" than as the same name four times, and a mixed machine keeps one group per model.
+std::string get_gpu_description() {
+    const auto names = get_gpu_names();
+
+    std::string out;
+    for (size_t i = 0; i < names.size();) {
+        size_t n = 1;
+        while (i + n < names.size() && names[i + n] == names[i])
+            n++;
+        if (!out.empty())
+            out += ", ";
+        if (n > 1)
+            out += std::to_string(n) + "x ";
+        out += names[i];
+        i += n;
+    }
+    return out;
+}
+
+#ifndef JFJOCH_USE_CUDA
+
 int32_t get_gpu_count() {
     return 0;
 }
 
+std::vector<std::string> get_gpu_names() {
+    return {};
+}
+
 void set_gpu(int32_t dev_id) {}
 
 void pin_gpu() {}

common/CUDAWrapper.cu

@@ -27,6 +27,22 @@ int32_t get_gpu_count() {
 
 }
 
+std::vector<std::string> get_gpu_names() {
+    std::vector<std::string> names;
+    const int32_t count = get_gpu_count();
+    names.reserve(count);
+    for (int32_t i = 0; i < count; i++) {
+        cudaDeviceProp prop{};
+        // A device that cannot be queried still exists and still gets work, so it is listed - just
+        // without a name. Losing the whole list over one unreadable device would be worse.
+        if (cudaGetDeviceProperties(&prop, i) == cudaSuccess)
+            names.emplace_back(prop.name);
+        else
+            names.emplace_back("unknown GPU");
+    }
+    return names;
+}
+
 void set_gpu(int32_t dev_id) {
     auto dev_count = get_gpu_count();
 

common/CUDAWrapper.h

@@ -4,8 +4,18 @@
 #pragma once
 
 #include <cstdint>
+#include <string>
+#include <vector>
 
 int32_t get_gpu_count();
+
+// Names of the visible GPUs, in device order and one entry per device, so repeated cards repeat.
+// Empty without CUDA and on a machine with no device, which is also what get_gpu_count() == 0 says.
+std::vector<std::string> get_gpu_names();
+
+// The same list collapsed for a person: "4x NVIDIA A100-SXM4-80GB", or several such groups separated
+// by ", " on a mixed machine. Empty when no GPU is visible.
+std::string get_gpu_description();
 void set_gpu(int32_t dev_id);
 
 // Pin the calling thread to the next GPU in round-robin order, using a process-wide counter

docs/CHANGELOG.md

@@ -3,6 +3,8 @@
 ### 1.0.0-rc.165
 This is an UNSTABLE release. It includes many experimental features, as well as many AI generated fixes. We recommend using rc.152 for production use.
 
+* The rugnux results report records how the run was invoked, what it cost and what it ran on: `COMMAND_LINE=` is the command line as one shell-ready line, `WALL_TIME=` the whole invocation in seconds, and `GPU_COUNT=` / `GPU=` how many GPUs were visible and which ones. The total wall time is also printed on stdout, next to the processing time it is slightly larger than.
+* rugnux says which GPUs it can see before it starts processing, so a machine that turns out to have none - a driver mismatch, a leftover `CUDA_VISIBLE_DEVICES` - is noticed while there is still time to stop rather than after a run that took far longer than it should have.
 * rugnux writes `<prefix>_unmerged.mtz` on every run that produces an output prefix, instead of only when asked for it with `--export-unmerged`. It is written in `--mode mx` and `--mode scale` and with `--no-merge`, alongside the merged files and replacing none of them. `--no-export-unmerged` turns it off.
 * `/start` asks the writer whether the run can be written before the detector is armed, so a run whose output file already exists, or whose output directory cannot be created, is refused up front with the writer's own message instead of failing once the detector is running. This needs the TCP image stream or the built-in HDF5 writer; the ZeroMQ stream has no way to answer and is unchanged.
 * An output data file already in the way is refused when the collection starts, not when the file is renamed into place at the end of it.

docs/RUGNUX.md

@@ -533,6 +533,23 @@ structure a script can consume without parsing prose.
 
 `REPORT_VERSION=` is the format's own version. Key names, table columns and the reason vocabulary
 below are an interface other software may depend on: they do not change without that number moving.
+Adding a key does not move it — a consumer that greps for what it needs is unaffected by one more
+line.
+
+The header block above section 1 records **how the result was produced**: `RUGNUX_VERSION=` and
+`RUGNUX_GIT=`, `DATE=`, `INPUT_FILE=` and `OUTPUT_PREFIX=`, plus
+
+- **`COMMAND_LINE=`** — the invocation as one shell-ready line, arguments containing spaces quoted.
+- **`WALL_TIME=`** — the whole invocation in seconds. It covers everything the process did, opening
+  the file and setting up included, so it is a little larger than the `Processing time` printed on
+  stdout, which starts once the analysis does.
+- **`GPU_COUNT=`** and **`GPU=`** — how many GPUs were visible and what they are, e.g.
+  `GPU= 4x NVIDIA A100-SXM4-80GB`; several models on one machine are listed as separate groups.
+  `GPU_COUNT= 0` appears on its own, with no `GPU=` line, when nothing was visible — which is the
+  first thing to check when a run took far longer than expected. rugnux prints the same line at
+  startup, before the run, so a missing GPU can be caught while there is still time to stop.
+
+Rates, per-image costs and progress remain on stdout only.
 
 Sections, in order: `1. DATA SET`, `2. INDEXING`, `3. GEOMETRY POST-REFINEMENT` (rotation only),
 `4. SPACE GROUP DETERMINATION`, `5. SCALING AND MERGING`, `6. TWINNING`, `7. RADIATION DAMAGE`,

rugnux/ResultReport.cpp

@@ -41,7 +41,8 @@ namespace {
 std::string RenderResultReport(const std::string &output_prefix,
                                const std::string &input_file,
                                const DiffractionExperiment &experiment,
-                               const ProcessResult &result) {
+                               const ProcessResult &result,
+                               const RunProvenance &provenance) {
     std::ostringstream os;
     const bool rotation = experiment.IsRotationIndexing();
     const bool merged = result.has_merge_statistics;
@@ -52,8 +53,8 @@ std::string RenderResultReport(const std::string &output_prefix,
        << BANNER << "\n\n"
        << " What this run determined, written next to its other output. The `KEY= value` lines and\n"
        << " the tables below are a stable interface - a script greps them, and REPORT_VERSION says\n"
-       << " when that interface last changed. Timing, rates and per-image progress are not here;\n"
-       << " they are on stdout.\n\n";
+       << " when that interface last changed. Rates and per-image progress are not here; they are\n"
+       << " on stdout.\n\n";
 
     Key(os, "REPORT_VERSION", REPORT_VERSION);
     Key(os, "RUGNUX_VERSION", jfjoch_version());
@@ -62,6 +63,20 @@ std::string RenderResultReport(const std::string &output_prefix,
     Key(os, "DATE", time_UTC(std::chrono::system_clock::now()));
     Key(os, "INPUT_FILE", input_file);
     Key(os, "OUTPUT_PREFIX", output_prefix);
+    // How the result was produced, what it cost and what it ran on, so the report stands on its own
+    // once the shell history it came from is gone. Absent rather than zero where the caller does not
+    // know them - the library and the viewer have no command line and no invocation to time.
+    if (!provenance.command_line.empty())
+        Key(os, "COMMAND_LINE", provenance.command_line);
+    if (provenance.wall_time_s > 0.0)
+        Key(os, "WALL_TIME", fmt::format("{:.2f}", provenance.wall_time_s));
+    if (provenance.gpu_count >= 0) {
+        Key(os, "GPU_COUNT", provenance.gpu_count);
+        // GPU_COUNT= 0 with no GPU= line is the CPU-only case, and saying so is the point: whether
+        // the GPUs were there is the first question about how long the run took.
+        if (!provenance.gpu_description.empty())
+            Key(os, "GPU", provenance.gpu_description);
+    }
 
     // ---------------------------------------------------------------- 1. DATA SET
     Section(os, "1. DATA SET");
@@ -351,7 +366,8 @@ void WriteResultReport(const std::string &output_prefix,
                        const std::string &input_file,
                        const DiffractionExperiment &experiment,
                        const ProcessResult &result,
-                       Logger &logger) {
+                       Logger &logger,
+                       const RunProvenance &provenance) {
     if (output_prefix.empty())
         return;   // "compute the statistics, persist nothing"
 
@@ -361,7 +377,7 @@ void WriteResultReport(const std::string &output_prefix,
     try {
         std::ofstream file(filename);
         file.exceptions(std::ios::failbit | std::ios::badbit);
-        file << RenderResultReport(output_prefix, input_file, experiment, result);
+        file << RenderResultReport(output_prefix, input_file, experiment, result, provenance);
     } catch (const std::exception &e) {
         logger.Warning("Could not write the results report {}: {}", filename, e.what());
     }

rugnux/ResultReport.h

@@ -12,16 +12,30 @@
 // <prefix>_report.txt - what the run DETERMINED, written next to the .mtz/.cif/.hkl on every run
 // that has an output prefix. Modelled on XDS's CORRECT.LP: prose and tables a crystallographer
 // reads top to bottom, with `KEY= value` assignment lines and fixed-width tables a script greps
-// without parsing prose. Timing, rates and progress are deliberately absent - those are stdout.
+// without parsing prose. Rates and per-image progress are deliberately absent - those are stdout;
+// the command line and the total wall time are here, because they say how this result was produced
+// and a report that has to be read next to a lost shell history is worth less.
 //
 // The format is an interface: key names, table columns and the reason vocabulary are stable, and
 // REPORT_VERSION is bumped if they ever change. See docs/RUGNUX.md.
 
+// How the run was produced: the invocation, what it cost, and what it ran on. The CLI is the only
+// caller that knows these, so they are passed in rather than read here. Each is left out of the
+// report when it is not given - a caller that cannot supply one must not have the report claim the
+// run was invoked by nobody, took no time, or saw no GPU.
+struct RunProvenance {
+    std::string command_line;      // argv as one shell-ready line
+    double wall_time_s = 0.0;      // the whole invocation; 0 = not measured
+    int32_t gpu_count = -1;        // -1 = not reported; 0 is a statement, not an omission
+    std::string gpu_description;   // "4x NVIDIA A100-SXM4-80GB"; empty when there is no GPU
+};
+
 // Renders the report. Exposed for testing; RunPipeline results are the only input.
 std::string RenderResultReport(const std::string &output_prefix,
                                const std::string &input_file,
                                const DiffractionExperiment &experiment,
-                               const ProcessResult &result);
+                               const ProcessResult &result,
+                               const RunProvenance &provenance = {});
 
 // Renders and writes <output_prefix>_report.txt. Does nothing when the prefix is empty (the
 // "compute statistics, persist nothing" mode). Never throws: a run that produced good reflections
@@ -30,4 +44,5 @@ void WriteResultReport(const std::string &output_prefix,
                        const std::string &input_file,
                        const DiffractionExperiment &experiment,
                        const ProcessResult &result,
-                       Logger &logger);
+                       Logger &logger,
+                       const RunProvenance &provenance = {});

rugnux/rugnux_cli.cpp

@@ -23,6 +23,7 @@
 #include "../common/DiffractionExperiment.h"
 #include "../common/PixelMask.h"
 #include "../common/print_license.h"
+#include "../common/CUDAWrapper.h"
 #include "../common/JFJochMath.h"
 #include "../image_analysis/bragg_integration/CalcISigma.h"
 #include "../image_analysis/geom_refinement/Calibrants.h"
@@ -566,6 +567,31 @@ namespace {
         if (auto *p = g_active_process.load())
             p->Cancel();
     }
+
+    // argv as one line, echoed at the top of the run and recorded in the results report. An argument
+    // that would not survive being pasted back into a shell is single-quoted, so a file prefix with a
+    // space in it comes back as the one argument it was.
+    std::string JoinCommandLine(int argc, char **argv) {
+        std::string out;
+        for (int i = 0; i < argc; i++) {
+            if (i > 0)
+                out += ' ';
+            const std::string arg = argv[i];
+            if (arg.find_first_of(" \t\n'\"\\$`*?()[]{}<>|&;#~") == std::string::npos) {
+                out += arg;
+                continue;
+            }
+            out += '\'';
+            for (char c : arg) {
+                if (c == '\'')
+                    out += "'\\''";
+                else
+                    out += c;
+            }
+            out += '\'';
+        }
+        return out;
+    }
 }
 
 // The body of main. Settings setters and the pipeline itself throw JFJochException on input the parser
@@ -573,11 +599,24 @@ namespace {
 // an unreadable file), so main wraps this and reports rather than letting the exception terminate the
 // process with no diagnostic and exit code 134.
 static int RunRugnux(int argc, char **argv) {
-    for (int i = 0; i < argc; i++) {
-        std::cout << argv[i] << " ";
-    }
-    std::cout << std::endl << std::endl;
+    // The whole invocation, reported at the end and written into the results report. Started before
+    // anything else so it covers reading the file and setting up as well as the processing.
+    const auto invocation_start = std::chrono::steady_clock::now();
+    RunProvenance provenance;
+    provenance.command_line = JoinCommandLine(argc, argv);
+    provenance.gpu_count = get_gpu_count();
+    provenance.gpu_description = get_gpu_description();
+    std::cout << provenance.command_line << std::endl << std::endl;
 
+    // Said before the run rather than after it: the GPUs are what makes rugnux fast, and a machine
+    // that turns out to have none - a driver mismatch, a CUDA_VISIBLE_DEVICES left over from another
+    // job - is worth knowing about while there is still time to stop and fix it.
+    if (provenance.gpu_count > 0)
+        std::cout << fmt::format("GPU:             {} ({} visible)",
+                                 provenance.gpu_description, provenance.gpu_count) << std::endl;
+    else
+        std::cout << "GPU:             none visible - running on the CPU, which is much slower"
+                  << std::endl;
 
     RegisterHDF5Filter();
 
@@ -1698,7 +1737,10 @@ static int RunRugnux(int argc, char **argv) {
         scale_result.error_model_b = error_model_b;
         scale_result.has_reference = !reference_data.empty();
         scale_result.twinning = twinning;
-        WriteResultReport(output_prefix, input_file, experiment, scale_result, logger);
+        provenance.wall_time_s = std::chrono::duration<double>(
+                std::chrono::steady_clock::now() - invocation_start).count();
+        std::cout << fmt::format("Total wall time:  {:.2f} s", provenance.wall_time_s) << std::endl;
+        WriteResultReport(output_prefix, input_file, experiment, scale_result, logger, provenance);
         return 0;
     }
 
@@ -2292,7 +2334,11 @@ static int RunRugnux(int argc, char **argv) {
 
     // The results report, next to the .mtz/.cif/.hkl. Written on every run with an output prefix -
     // including --no-merge, which still determined an indexing and geometry result worth recording.
-    WriteResultReport(output_prefix, input_file, experiment, result, logger);
+    // The wall time is the whole invocation, which is more than result.total_time_s: that one starts
+    // inside Rugnux::Run, so it counts neither opening the file nor setting up the analysis.
+    provenance.wall_time_s = std::chrono::duration<double>(
+            std::chrono::steady_clock::now() - invocation_start).count();
+    WriteResultReport(output_prefix, input_file, experiment, result, logger, provenance);
 
     // The space-group search is rendered here (not in the library) so the viewer does not emit it on
     // stdout and the CLI owns the format.
@@ -2307,6 +2353,7 @@ static int RunRugnux(int argc, char **argv) {
     // and throughput stay per-pass: they say how fast rugnux moves through images, which running a
     // second pass does not change.
     std::cout << fmt::format("Processing time: {:.2f} s", result.total_time_s) << std::endl;
+    std::cout << fmt::format("Total wall time: {:.2f} s", provenance.wall_time_s) << std::endl;
     if (result.pass_count > 1)
         std::cout << fmt::format("  last pass:     {:.2f} s (of {} passes)",
                                  result.processing_time_s, result.pass_count) << std::endl;

tests/ResultReportTest.cpp

@@ -7,6 +7,7 @@
 #include "../image_analysis/scale_merge/Merge.h"
 #include "../reader/JFJochHDF5Reader.h"
 #include "../rugnux/ResultReport.h"
+#include "../common/CUDAWrapper.h"
 #include "../writer/FileWriter.h"
 
 // Two synthetic ranges, one of each shape the report has to handle.
@@ -182,3 +183,56 @@ TEST_CASE("SweepQuality_HDF5RoundTrip", "[HDF5][Full][Diagnostics]") {
     REQUIRE(H5Fget_obj_count(H5F_OBJ_ALL, H5F_OBJ_ALL) == 0);
     remove("sweep_quality_roundtrip_master.h5");
 }
+
+// The command line, the wall time and the GPUs say how the result was produced, what it cost and what
+// it ran on, so the report can be read on its own once the shell history is gone. They come from the
+// CLI, which is the only caller that knows them; a caller that does not - the library, the viewer -
+// must get a report without them rather than one claiming the run was invoked by nobody, took no
+// time, and saw no GPU.
+TEST_CASE("ResultReport_ProvenanceKeys", "[Diagnostics]") {
+    DiffractionExperiment x(DetJF(1));
+    x.ImagesPerTrigger(600);
+
+    ProcessResult result;
+    result.images_processed = 600;
+    result.consensus_cell = UnitCell{.a = 79.0f, .b = 79.0f, .c = 38.0f,
+                                     .alpha = 90.0f, .beta = 90.0f, .gamma = 90.0f};
+
+    RunProvenance provenance;
+    provenance.command_line = "rugnux -o prefix in.h5";
+    provenance.wall_time_s = 262.409;
+    provenance.gpu_count = 4;
+    provenance.gpu_description = "4x NVIDIA A100-SXM4-80GB";
+
+    const auto text = RenderResultReport("prefix", "in.h5", x, result, provenance);
+    CHECK(text.find("\nCOMMAND_LINE= rugnux -o prefix in.h5\n") != std::string::npos);
+    CHECK(text.find("\nWALL_TIME= 262.41\n") != std::string::npos);
+    CHECK(text.find("\nGPU_COUNT= 4\n") != std::string::npos);
+    CHECK(text.find("\nGPU= 4x NVIDIA A100-SXM4-80GB\n") != std::string::npos);
+
+    // A machine with no GPU says so - GPU_COUNT= 0 is a statement about why the run took as long as
+    // it did, and only the name list has nothing to report.
+    RunProvenance cpu_only;
+    cpu_only.gpu_count = 0;
+    const auto cpu_text = RenderResultReport("prefix", "in.h5", x, result, cpu_only);
+    CHECK(cpu_text.find("\nGPU_COUNT= 0\n") != std::string::npos);
+    CHECK(cpu_text.find("\nGPU= ") == std::string::npos);
+
+    const auto without = RenderResultReport("prefix", "in.h5", x, result);
+    CHECK(without.find("COMMAND_LINE=") == std::string::npos);
+    CHECK(without.find("WALL_TIME=") == std::string::npos);
+    CHECK(without.find("GPU_COUNT=") == std::string::npos);
+}
+
+// get_gpu_description collapses repeats, so a four-card machine reads as one line rather than the
+// same name four times. Build-independent: without CUDA there are no names and it is empty.
+TEST_CASE("ResultReport_GpuDescription", "[Diagnostics]") {
+    const auto names = get_gpu_names();
+    CHECK(names.size() == static_cast<size_t>(std::max(0, get_gpu_count())));
+
+    const auto description = get_gpu_description();
+    if (names.empty())
+        CHECK(description.empty());
+    else
+        CHECK(description.find(names.front()) != std::string::npos);
+}