jfjoch_process: logging more information for optimization
Some checks failed
Build Packages / build:rpm (ubuntu2404_nocuda) (push) Successful in 14m42s
Build Packages / build:rpm (rocky8_nocuda) (push) Successful in 16m0s
Build Packages / build:rpm (rocky9_nocuda) (push) Successful in 16m18s
Build Packages / build:rpm (ubuntu2204_nocuda) (push) Successful in 16m49s
Build Packages / Build documentation (push) Successful in 42s
Build Packages / Generate python client (push) Successful in 1m17s
Build Packages / Create release (push) Has been skipped
Build Packages / build:rpm (rocky8) (push) Successful in 18m31s
Build Packages / build:rpm (rocky8_sls9) (push) Successful in 18m48s
Build Packages / build:rpm (rocky9) (push) Successful in 19m45s
Build Packages / build:rpm (rocky9_sls9) (push) Successful in 19m49s
Build Packages / build:rpm (ubuntu2404) (push) Successful in 8m49s
Build Packages / build:rpm (ubuntu2204) (push) Successful in 10m11s
Build Packages / Unit tests (push) Has been cancelled

This commit is contained in:
2026-03-27 15:31:59 +01:00
parent 33410e1544
commit fa69ac89f3

View File

@@ -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", "<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;
@@ -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<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 ...");
@@ -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<double>(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<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.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", "<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";
@@ -764,12 +775,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);
}