jfjoch_process: reorder sp-search routine with timer-output

VERSION

@@ -1 +1 @@
-1.0.0-rc.133
+1.0.0-rc.134

image_analysis/scale_merge/ScaleAndMerge.cpp

@@ -7,6 +7,7 @@
 
 #include <thread>
 #include <iostream>
+#include <iomanip>
 #include <algorithm>
 #include <cmath>
 #include <limits>
@@ -235,6 +236,7 @@ namespace {
         int img_id = 0;
         int hkl_slot = -1;
         double sigma = 0.0;
+        mutable bool selected = true;
     };
 
     struct CorrectedObs {
@@ -243,6 +245,108 @@ namespace {
         double sigma_corr;
     };
 
+    void select_reflections_by_quasi_random(const std::vector<ObsRef> &obs,
+        const ScaleMergeOptions &opt,
+        std::vector<bool> &hkl_selected,
+        double Isigma_cutoff = 1.0,
+        int min_per_bin = 2500, // needs optimization
+        int max_per_bin = 80000,
+        int n_resolution_bins = 20) {
+        float stat_d_min = std::numeric_limits<float>::max();
+        float stat_d_max = 0.0f;
+
+        const gemmi::SpaceGroup &sg = *opt.space_group;
+        const gemmi::GroupOps gops = sg.operations();
+        int n_operator = gops.order();
+
+        struct HKLStats {
+            int n = 0;
+            float d = std::numeric_limits<float>::max();
+            int shell_id = 0;
+        };
+        const int nhkl = static_cast<int>(hkl_selected.size());
+        std::vector<HKLStats> per_hkl(nhkl);
+        int reflection_above_cutoff = 0;
+
+        for (const auto &o: obs) {
+            if (o.r->I / o.r->sigma < Isigma_cutoff) {
+                o.selected = false;
+                continue;
+            }
+
+            const auto d = o.r->d;
+            reflection_above_cutoff += 1;
+            if (std::isfinite(d) && d > 0.0f) {
+                if (opt.d_min_limit_A > 0.0 && d < static_cast<float>(opt.d_min_limit_A))
+                    continue;
+                stat_d_min = std::min(stat_d_min, d);
+                stat_d_max = std::max(stat_d_max, d);
+                auto &hs = per_hkl[o.hkl_slot];
+                hs.n += 1;
+                hs.d = d;
+            }
+        }
+
+        std::cout << "Reflections of I/sigma > " << Isigma_cutoff << " : " << reflection_above_cutoff << std::endl;
+        if (reflection_above_cutoff < min_per_bin * n_resolution_bins) {
+            std::cout << "No additional selection applied before scaling" << std::endl;
+            return;
+        }
+
+        if (stat_d_min < stat_d_max && stat_d_min > 0.0f) {
+            const float d_min_pad = stat_d_min * 0.999f;
+            const float d_max_pad = stat_d_max * 1.001f;
+            ResolutionShells scaling_shells(d_min_pad, d_max_pad, n_resolution_bins);
+
+            for (int h = 0; h < nhkl; ++h) {
+                const auto d = per_hkl[h].d;
+                if (std::isfinite(d) && d > 0.0f) {
+                    if (opt.d_min_limit_A > 0.0 && d < static_cast<float>(opt.d_min_limit_A))
+                        continue;
+                    auto s = scaling_shells.GetShell(d);
+                    if (s.has_value())
+                        per_hkl[h].shell_id = s.value();
+                }
+            }
+
+            // Accumulators per shell
+            struct ShellAccum {
+                int obs_unique = 0;
+                int obs_total = 0;
+                bool selected = true;
+            };
+            std::vector<ShellAccum> shell_acc(n_resolution_bins);
+
+            for (int h = 0; h < nhkl; ++h) {
+                auto &sa = shell_acc[per_hkl[h].shell_id];
+                if (sa.obs_unique  * n_operator  > min_per_bin * 1.2 || sa.obs_total > max_per_bin)
+                    hkl_selected[h] = false;
+                else
+                    sa.obs_unique += 1;
+                    sa.obs_total += per_hkl[h].n;
+            }
+
+            const auto shell_min_res = scaling_shells.GetShellMinRes();
+
+            std::cout << "| d-mean | n_refl_uni | n_refl_tot | selection |" << std::endl;
+            for (int n=0; n < n_resolution_bins; ++n) {
+                if (shell_acc[n].obs_unique * n_operator < min_per_bin)
+                    shell_acc[n].selected = false;
+                if (shell_min_res[n] <= 0.0f) continue;
+                std::cout << std::setw(8) << std::fixed << std::setprecision(3) << shell_min_res[n]
+                          << std::setw(12) << std::fixed << std::setprecision(0) << shell_acc[n].obs_unique
+                          << std::setw(12) << shell_acc[n].obs_total
+                          << "      " << shell_acc[n].selected << std::endl;
+            }
+
+            for (int h = 0; h < nhkl; ++h) {
+                auto &sa = shell_acc[per_hkl[h].shell_id];
+                if (!sa.selected)
+                    hkl_selected[h] = false;
+            }
+       }
+    }
+
     void scale(const ScaleMergeOptions &opt,
                std::vector<double> &g,
                std::vector<double> &mosaicity,
@@ -250,10 +354,12 @@ namespace {
                const std::vector<uint8_t> &image_slot_used,
                bool rotation_crystallography,
                size_t nhkl,
-               const std::vector<ObsRef> &obs) {
+               const std::vector<ObsRef> &obs,
+               bool selection) {
         ceres::Problem problem;
 
         std::vector<double> Itrue(nhkl, 0.0);
+        std::vector<bool> hkl_selected(nhkl, true);
 
         // Initialize Itrue from per-HKL median of observed intensities
         {
@@ -277,8 +383,12 @@ namespace {
 
         double wedge = opt.wedge_deg.value_or(0.0);
 
+        select_reflections_by_quasi_random(obs, opt, hkl_selected);
+
         std::vector<bool> is_valid_hkl_slot(nhkl, false);
         for (const auto &o: obs) {
+            if (!o.selected) continue;
+            if (!hkl_selected[o.hkl_slot]) continue;
             switch (opt.partiality_model) {
                 case ScaleMergeOptions::PartialityModel::Rotation: {
                     auto *cost = new ceres::AutoDiffCostFunction<IntensityRotResidual, 1, 1, 1, 1, 1>(
@@ -398,6 +508,7 @@ namespace {
         options.function_tolerance = 1e-4;
 
         ceres::Solver::Summary summary;
+        std::cout << "Now start the ceres-solver with residual blocks: " << problem.NumResidualBlocks() << std::endl;
         ceres::Solve(options, &problem, &summary);
         std::cout << summary.FullReport() << std::endl;
     }
@@ -694,6 +805,7 @@ namespace {
                 o.img_id = img_id;
                 o.hkl_slot = hkl_slot;
                 o.sigma = sigma;
+                o.selected = true;
                 obs.push_back(o);
             }
         }
@@ -707,6 +819,7 @@ ScaleMergeResult ScaleAndMergeReflectionsCeres(const std::vector<std::vector<Ref
         throw std::invalid_argument("image_cluster must be positive");
 
     const bool rotation_crystallography = opt.wedge_deg.has_value();
+    const bool selection = opt.selection;
 
     size_t nrefl = 0;
     for (const auto &i: observations)
@@ -744,7 +857,8 @@ ScaleMergeResult ScaleAndMergeReflectionsCeres(const std::vector<std::vector<Ref
         }
     }
 
-    scale(opt, g, mosaicity, R_sq, image_slot_used, rotation_crystallography, nhkl, obs);
+    std::cout << "Now scale the reflections: " << nrefl << std::endl;
+    scale(opt, g, mosaicity, R_sq, image_slot_used, rotation_crystallography, nhkl, obs, selection);
 
     ScaleMergeResult out;
 

image_analysis/scale_merge/ScaleAndMerge.h

@@ -50,6 +50,8 @@ struct ScaleMergeOptions {
 
     bool refine_wedge = false;
 
+    bool selection = true;
+
     enum class PartialityModel {Fixed, Rotation, Unity, Still} partiality_model = PartialityModel::Fixed;
 };
 

tools/jfjoch_process.cpp

@@ -2,6 +2,7 @@
 // SPDX-License-Identifier: GPL-3.0-only
 
 #include <iostream>
+#include <iomanip>
 #include <vector>
 #include <string>
 #include <unistd.h>
@@ -44,12 +45,15 @@ void print_usage(Logger &logger) {
     logger.Info("   -d<num>    High resolution limit for spot finding (default: 1.5)");
     logger.Info("   -D<num>    High resolution limit for scaling/merging (default: 0.0; no limit)");
     logger.Info("   -S<num>    Space group number");
-    logger.Info("   -M         Scale and merge (refine mosaicity) and write scaled.hkl + image.dat");
+    logger.Info("   -M[num]    Scale and merge (refine mosaicity) and write scaled.hkl + image.dat, unless indexing rate is below threshold (default: 0.5)");
     logger.Info("   -P<txt>    Partiality refinement fixed|rot|unity (default: fixed)");
     logger.Info("   -A         Anomalous mode (don't merge Friedel pairs)");
     logger.Info("   -C<cell>   Fix reference unit cell: -C\"a,b,c,alpha,beta,gamma\" (comma-separated, no spaces; quotes optional)");
     logger.Info("   -c<num>    Max spot count (default: 250)");
-    logger.Info("   -W         HDF5 file with analysis results is written");
+    logger.Info("   -W<txt>    HDF5 file with analysis results is written. 'l' or 'light' deactivates image-output");
+    logger.Info("   -T<num>    Noise sigma level for spot finding (default: 3.0)");
+    logger.Info("   -a         Use all reflection for scaling without filtering (default: false)");
+    logger.Info("   -w         Reflection wedge in scaling (default: false)");
 }
 
 void trim_in_place(std::string& t) {
@@ -60,6 +64,36 @@ void trim_in_place(std::string& t) {
     t = t.substr(b, e - b);
 };
 
+void print_statistics(Logger &logger, const MergeStatistics &stats) {
+    logger.Info("");
+    logger.Info("  {:>8s} {:>8s} {:>8s} {:>8s} {:>8s} {:>10s}",
+                "d_min", "N_obs", "N_uniq", "Rmeas", "<I/sig>", "Complete");
+    logger.Info("  {:->8s} {:->8s} {:->8s} {:->8s} {:->8s} {:->10s}",
+                "", "", "", "", "", "");
+    for (const auto &sh: stats.shells) {
+        if (sh.unique_reflections == 0)
+            continue;
+        std::string compl_str = (sh.completeness > 0.0)
+                                    ? fmt::format("{:8.1f}%", sh.completeness * 100.0)
+                                    : "      N/A";
+        logger.Info("  {:8.2f} {:8d} {:8d} {:8.3f}% {:8.1f} {:>10s}",
+                    sh.d_min, sh.total_observations, sh.unique_reflections,
+                    sh.rmeas * 100, sh.mean_i_over_sigma, compl_str);
+    }
+    {
+        const auto &ov = stats.overall;
+        logger.Info("  {:->8s} {:->8s} {:->8s} {:->8s} {:->8s} {:->10s}",
+                    "", "", "", "", "", "");
+        std::string compl_str = (ov.completeness > 0.0)
+                                    ? fmt::format("{:8.1f}%", ov.completeness * 100.0)
+                                    : "      N/A";
+        logger.Info("  {:>8s} {:8d} {:8d} {:8.3f}% {:8.1f} {:>10s}",
+                    "Overall", ov.total_observations, ov.unique_reflections,
+                    ov.rmeas * 100, ov.mean_i_over_sigma, compl_str);
+    }
+    logger.Info("");
+}
+
 std::optional<UnitCell> parse_unit_cell_arg(const char* arg)  {
     if (!arg)
         return std::nullopt;
@@ -132,8 +166,13 @@ int main(int argc, char **argv) {
     std::optional<int> space_group_number;
     std::optional<UnitCell> fixed_reference_unit_cell;
     bool write_output = false;
+    bool write_output_noimage = false;
+    bool filtering = true;
     std::optional<int64_t> max_spot_count_override;
+    float sigma_spot_finding = 3.0;
+    std::optional<float> merging_threshold;
     IndexingAlgorithmEnum indexing_algorithm = IndexingAlgorithmEnum::Auto;
+    bool refine_wedge = false;
 
     ScaleMergeOptions::PartialityModel partiality_model = ScaleMergeOptions::PartialityModel::Fixed;
 
@@ -146,7 +185,7 @@ int main(int argc, char **argv) {
     }
 
     int opt;
-    while ((opt = getopt(argc, argv, "o:N:s:e:vc:R::FX:xd:S:MP:AD:C:W")) != -1) {
+    while ((opt = getopt(argc, argv, "o:N:s:e:vc:R::FX:xd:S:M::P:AD:C:T:W:aw")) != -1) {
         switch (opt) {
             case 'o':
                 output_prefix = optarg;
@@ -162,6 +201,10 @@ int main(int argc, char **argv) {
                 break;
             case 'W':
                 write_output = true;
+                if (strcmp(optarg, "light") == 0 || strcmp(optarg, "l") == 0) {
+                    write_output_noimage = true;
+                    logger.Warning("Image data will not be saved.");
+                }
                 break;
             case 'v':
                 verbose = true;
@@ -204,6 +247,12 @@ int main(int argc, char **argv) {
             case 'x':
                 refine_beam_center = false;
                 break;
+            case 'a':
+                filtering = false;
+                break;
+            case 'w':
+                refine_wedge = true;
+                break;
             case 'D':
                 d_min_scale_merge = atof(optarg);
                 logger.Info("High resolution limit for scaling/merging set to {:.2f} A", d_min_spot_finding);
@@ -213,10 +262,15 @@ int main(int argc, char **argv) {
                 break;
             case 'M':
                 run_scaling = true;
+                if (optarg) merging_threshold = atof(optarg);
                 break;
             case 'A':
                 anomalous_mode = true;
                 break;
+            case 'T':
+                sigma_spot_finding = atof(optarg);
+                logger.Info("Noise threshold level for spot finding set to {:.2f} sigma", sigma_spot_finding);
+                break;
             case 'C': {
                 auto uc = parse_unit_cell_arg(optarg);
                 if (!uc.has_value()) {
@@ -296,8 +350,11 @@ int main(int argc, char **argv) {
     experiment.OverwriteExistingFiles(true);
     experiment.PolarizationFactor(0.99);
 
-    if (fixed_reference_unit_cell.has_value())
+    if (fixed_reference_unit_cell.has_value()) {
         experiment.SetUnitCell(*fixed_reference_unit_cell);
+    } else {
+        experiment.SetUnitCell({});
+    }
 
     if (max_spot_count_override.has_value()) {
         experiment.MaxSpotCount(max_spot_count_override.value());
@@ -308,6 +365,8 @@ int main(int argc, char **argv) {
     IndexingSettings indexing_settings;
     indexing_settings.Algorithm(indexing_algorithm);
     indexing_settings.RotationIndexing(rotation_indexing);
+    if (rotation_indexing)
+        logger.Info("Rotation indexing is activated.");
     if (rotation_indexing_range.has_value())
         indexing_settings.RotationIndexingMinAngularRange_deg(rotation_indexing_range.value());
 
@@ -317,10 +376,27 @@ int main(int argc, char **argv) {
         indexing_settings.GeomRefinementAlgorithm(GeomRefinementAlgorithmEnum::None);
     experiment.ImportIndexingSettings(indexing_settings);
 
+    switch (experiment.GetIndexingAlgorithm()) {
+        case IndexingAlgorithmEnum::FFBIDX:
+            logger.Info("Indexer used: FFBIDX");
+            break;
+        case IndexingAlgorithmEnum::FFTW:
+            logger.Info("Indexer used: FFTW");
+            break;
+        case IndexingAlgorithmEnum::FFT:
+            logger.Info("Indexer used: FFT (CUDA)");
+            break;
+        case IndexingAlgorithmEnum::None:
+            logger.Warning("Indexer not defined!");
+            return 0;
+        default: ;
+    }
+
     SpotFindingSettings spot_settings;
     spot_settings.enable = true;
     spot_settings.indexing = true;
     spot_settings.high_resolution_limit = d_min_spot_finding;
+    spot_settings.signal_to_noise_threshold = sigma_spot_finding;
     if (d_min_scale_merge > 0)
         spot_settings.high_resolution_limit = d_min_spot_finding;
 
@@ -396,6 +472,10 @@ int main(int argc, char **argv) {
         compressed_buffer.resize(MaxCompressedSize(experiment.GetCompressionAlgorithm(),
                                                    experiment.GetPixelsNum(),
                                                    experiment.GetByteDepthImage()));
+        auto size = compressor.Compress(compressed_buffer.data(),
+                            compressed_buffer.data(),
+                            experiment.GetPixelsNum(),
+                            sizeof(uint8_t));
 
         // Thread-local analysis resources
         MXAnalysisWithoutFPGA analysis(experiment, mapping, pixel_mask, indexer);
@@ -446,10 +526,11 @@ int main(int argc, char **argv) {
             auto image_end_time = std::chrono::high_resolution_clock::now();
             std::chrono::duration<float> image_duration = image_end_time - image_start_time;
 
-            auto size = compressor.Compress(compressed_buffer.data(),
-                                            img->Image().data(),
-                                            experiment.GetPixelsNum(),
-                                            sizeof(int32_t));
+            if (!write_output_noimage)
+                size = compressor.Compress(compressed_buffer.data(),
+                                                img->Image().data(),
+                                                experiment.GetPixelsNum(),
+                                                sizeof(int32_t));
 
             msg.image = CompressedImage(compressed_buffer.data(),
                                         size, experiment.GetXPixelsNum(),
@@ -482,7 +563,7 @@ int main(int argc, char **argv) {
             }
 
             // Progress log
-            if (current_idx_offset > 0 && current_idx_offset % 100 == 0) {
+            if ((current_idx_offset > 0 && (current_idx_offset+1) % 100 == 0) || image_idx == end_image - 1) {
                 std::optional<float> indexing_rate;
                 {
                     std::lock_guard<std::mutex> lock(plots_mutex);
@@ -491,11 +572,21 @@ int main(int argc, char **argv) {
 
                 if (indexing_rate.has_value()) {
                     logger.Info("Processed {} / {} images (indexing rate {:.1f}%)",
-                                current_idx_offset, images_to_process,
+                                current_idx_offset+1, images_to_process,
                                 indexing_rate.value() * 100.0f);
                 } else {
                     logger.Info("Processed {} / {} images (indexing rate N/A)",
-                                current_idx_offset, images_to_process);
+                                current_idx_offset+1, images_to_process);
+                }
+                if (image_idx == end_image - 1) {
+                    if (!merging_threshold.has_value()) merging_threshold = 0.5f;
+                    if (!indexing_rate.has_value()) {
+                        run_scaling = false;
+                    } else if (indexing_rate.value() < merging_threshold) {
+                        run_scaling = false;
+                        logger.Warning("Not proceed to scale and merge with lower indexing rate: {:.1f}%",
+                            indexing_rate.value()*100.0f);
+                    }
                 }
             }
         }
@@ -547,7 +638,6 @@ int main(int argc, char **argv) {
         logger.Info("Rotation Indexing found lattice");
     }
 
-    // --- Optional: run scaling (mosaicity refinement) on accumulated reflections ---
     // --- Optional: run scaling (mosaicity refinement) on accumulated reflections ---
     if (run_scaling) {
         logger.Info("Running scaling (mosaicity refinement) ...");
@@ -558,6 +648,8 @@ int main(int argc, char **argv) {
         scale_opts.max_solver_time_s = 240.0; // generous cutoff for now
         scale_opts.merge_friedel = !anomalous_mode;
         scale_opts.d_min_limit_A = d_min_scale_merge.value_or(0.0);
+        scale_opts.selection = filtering;
+        scale_opts.refine_wedge = refine_wedge;
 
         const bool fixed_space_group = space_group || experiment.GetGemmiSpaceGroup().has_value();
 
@@ -565,12 +657,16 @@ int main(int argc, char **argv) {
             scale_opts.space_group = *space_group;
         else
             scale_opts.space_group = experiment.GetGemmiSpaceGroup();
+        if (scale_opts.space_group->number == 0) scale_opts.space_group = *gemmi::find_spacegroup_by_number(1);
 
+        logger.Info("Starting SG-no.: {}", scale_opts.space_group->number);
         auto scale_start = std::chrono::steady_clock::now();
         auto scale_result = indexer.ScaleRotationData(scale_opts);
         auto scale_end = std::chrono::steady_clock::now();
         double scale_time = std::chrono::duration<double>(scale_end - scale_start).count();
 
+        if (scale_result) print_statistics(logger, scale_result->statistics);
+
         if (scale_result && !fixed_space_group) {
             logger.Info("Searching for space group from P1-merged reflections ...");
 
@@ -579,13 +675,16 @@ int main(int argc, char **argv) {
             sg_opts.centering = '\0';
             sg_opts.merge_friedel = !anomalous_mode;
             sg_opts.d_min_limit_A = d_min_scale_merge.value_or(0.0);
-            sg_opts.min_i_over_sigma = 0.0;
+            sg_opts.min_i_over_sigma = 4.0; // 0.0; follows the DIALS's default
             sg_opts.min_operator_cc = 0.80;
             sg_opts.min_pairs_per_operator = 20;
             sg_opts.min_total_compared = 100;
             sg_opts.test_systematic_absences = true;
 
+            auto sg_search_start = std::chrono::steady_clock::now();
             const auto sg_search = SearchSpaceGroup(scale_result->merged, sg_opts);
+            auto sg_search_end = std::chrono::steady_clock::now();
+            double sg_search_time = std::chrono::duration<double>(sg_search_end - sg_search_start).count();
 
             logger.Info("");
             {
@@ -599,17 +698,24 @@ int main(int argc, char **argv) {
             logger.Info("");
 
             if (sg_search.best_space_group.has_value()) {
-                logger.Info("Re-running scaling in detected space group {}", sg_search.best_space_group->short_name());
+                if (sg_search.best_space_group->number != 0) {
+                    if (sg_search.best_space_group->number != scale_opts.space_group->number) {
+                        logger.Info("Re-running scaling in detected space group {}", sg_search.best_space_group->short_name());
+                        logger.Info("SG-search wall-clock time: {:.2f} s", sg_search_time);
 
-                scale_opts.space_group = *sg_search.best_space_group;
+                        scale_opts.space_group = *sg_search.best_space_group;
 
-                auto rescale_start = std::chrono::steady_clock::now();
-                auto refined_scale_result = indexer.ScaleRotationData(scale_opts);
-                auto rescale_end = std::chrono::steady_clock::now();
+                        auto rescale_start = std::chrono::steady_clock::now();
+                        auto refined_scale_result = indexer.ScaleRotationData(scale_opts);
+                        auto rescale_end = std::chrono::steady_clock::now();
 
-                if (refined_scale_result) {
-                    scale_result = std::move(refined_scale_result);
-                    scale_time += std::chrono::duration<double>(rescale_end - rescale_start).count();
+                        if (refined_scale_result) {
+                            scale_result = std::move(refined_scale_result);
+                            scale_time += std::chrono::duration<double>(rescale_end - rescale_start).count();
+                        }
+                    } else {
+                        logger.Info("No space group update indicated.");
+                    }
                 }
             } else {
                 logger.Warning("No space group accepted; keeping P1-merged result");
@@ -623,36 +729,7 @@ int main(int argc, char **argv) {
                         scale_time, scale_result->merged.size());
 
             // Print resolution-shell statistics table
-            {
-                const auto &stats = scale_result->statistics;
-                logger.Info("");
-                logger.Info("  {:>8s} {:>8s} {:>8s} {:>8s} {:>8s} {:>10s}",
-                            "d_min", "N_obs", "N_uniq", "Rmeas", "<I/sig>", "Complete");
-                logger.Info("  {:->8s} {:->8s} {:->8s} {:->8s} {:->8s} {:->10s}",
-                            "", "", "", "", "", "");
-                for (const auto &sh: stats.shells) {
-                    if (sh.unique_reflections == 0)
-                        continue;
-                    std::string compl_str = (sh.completeness > 0.0)
-                                                ? fmt::format("{:8.1f}%", sh.completeness * 100.0)
-                                                : "      N/A";
-                    logger.Info("  {:8.2f} {:8d} {:8d} {:8.3f}% {:8.1f} {:>10s}",
-                                sh.d_min, sh.total_observations, sh.unique_reflections,
-                                sh.rmeas * 100, sh.mean_i_over_sigma, compl_str);
-                }
-                {
-                    const auto &ov = stats.overall;
-                    logger.Info("  {:->8s} {:->8s} {:->8s} {:->8s} {:->8s} {:->10s}",
-                                "", "", "", "", "", "");
-                    std::string compl_str = (ov.completeness > 0.0)
-                                                ? fmt::format("{:8.1f}%", ov.completeness * 100.0)
-                                                : "      N/A";
-                    logger.Info("  {:>8s} {:8d} {:8d} {:8.3f}% {:8.1f} {:>10s}",
-                                "Overall", ov.total_observations, ov.unique_reflections,
-                                ov.rmeas * 100, ov.mean_i_over_sigma, compl_str);
-                }
-                logger.Info("");
-            }
+            print_statistics(logger, scale_result->statistics);
 
             {
                 const std::string img_path = output_prefix + "_image.dat";
@@ -698,6 +775,8 @@ int main(int argc, char **argv) {
                         cif_meta.unit_cell = rotation_indexer_ret->lattice.GetUnitCell();
                     } else if (experiment.GetUnitCell().has_value()) {
                         cif_meta.unit_cell = experiment.GetUnitCell().value();
+                    } else {
+                        logger.Warning("No UnitCell output");
                     }
 
                     if (scale_opts.space_group.has_value()) {
@@ -745,12 +824,11 @@ int main(int argc, char **argv) {
     double frame_rate = static_cast<double>(images_to_process) / processing_time;
 
     logger.Info("");
-    logger.Info("Processing time: {:.2f} s", processing_time);
-    logger.Info("Frame rate:      {:.2f} Hz", frame_rate);
-    logger.Info("Total throughput:{:.2f} MB/s", throughput_MBs);
-
+    logger.Info("Processing time (excl. scaling): {:8.2f} s", processing_time);
+    logger.Info("Frame rate:                      {:8.2f} Hz", frame_rate);
+    logger.Info("Total throughput:                {:8.2f} MB/s", throughput_MBs);
     // Print extended stats similar to Receiver
-    if (!end_msg.indexing_rate.has_value()) {
+    if (end_msg.indexing_rate.has_value()) {
         logger.Info("Indexing rate:   {:.2f}%", end_msg.indexing_rate.value() * 100.0);
     }