diff --git a/tools/jfjoch_process.cpp b/tools/jfjoch_process.cpp index 9a89db17..a4f892dd 100644 --- a/tools/jfjoch_process.cpp +++ b/tools/jfjoch_process.cpp @@ -61,6 +61,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", "", "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 parse_unit_cell_arg(const char* arg) { if (!arg) return std::nullopt; @@ -584,12 +614,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(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 ..."); @@ -604,7 +638,10 @@ int main(int argc, char **argv) { 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(sg_search_end - sg_search_start).count(); logger.Info(""); { @@ -618,17 +655,20 @@ 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) { + 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(rescale_end - rescale_start).count(); + if (refined_scale_result) { + scale_result = std::move(refined_scale_result); + scale_time += std::chrono::duration(rescale_end - rescale_start).count(); + } } } else { logger.Warning("No space group accepted; keeping P1-merged result"); @@ -642,36 +682,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", "", "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"; @@ -764,12 +775,11 @@ int main(int argc, char **argv) { double frame_rate = static_cast(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); }