From 15be4ff6d73229f72f553d2dc01f2df171e1266b Mon Sep 17 00:00:00 2001 From: Filip Leonarski Date: Tue, 21 Apr 2026 16:12:43 +0200 Subject: [PATCH] jfjoch_broker: Measure preprocessing time for images --- common/JFJochMessages.h | 1 + docs/CBOR.md | 1 + frame_serialize/CBORStream2Deserializer.cpp | 2 ++ frame_serialize/CBORStream2Serializer.cpp | 1 + image_analysis/MXAnalysisWithoutFPGA.cpp | 4 ++++ receiver/JFJochReceiverFPGA.cpp | 5 +++++ receiver/JFJochReceiverPlots.cpp | 23 ++++++++++++++++----- receiver/JFJochReceiverPlots.h | 2 ++ tools/jfjoch_process.cpp | 3 ++- 9 files changed, 36 insertions(+), 6 deletions(-) diff --git a/common/JFJochMessages.h b/common/JFJochMessages.h index 9d51635f..82919f39 100644 --- a/common/JFJochMessages.h +++ b/common/JFJochMessages.h @@ -91,6 +91,7 @@ struct DataMessage { std::optional refinement_time_s; std::optional bragg_prediction_time_s; std::optional integration_time_s; + std::optional preprocessing_time_s; std::vector spots; std::optional spot_count; diff --git a/docs/CBOR.md b/docs/CBOR.md index cabe07f0..ec1d4c78 100644 --- a/docs/CBOR.md +++ b/docs/CBOR.md @@ -161,6 +161,7 @@ See [DECTRIS documentation](https://github.com/dectris/documentation/tree/main/s | profile_radius | float | Profile radius of the image - describes distance of observed reflections from the Ewald sphere \[Angstrom^-1\] | | | | mosaicity | float | Angular range of spots in image from a rotation scan \[degree\] | | | | b_factor | float | Estimated B-factor (Angstrom^2) | | | +| preprocessing_time | float | Time spent on preparing the image for analysis \[s\] | | | | spot_finding_time | float | Time spent on spot finding \[s\] | | | | indexing_time | float | Time spent on indexing \[s\] | | | | refinement_time | float | Time spent on refinement of indexing solution and experimental geometry \[s\] | | | diff --git a/frame_serialize/CBORStream2Deserializer.cpp b/frame_serialize/CBORStream2Deserializer.cpp index 23817913..5cda6c73 100644 --- a/frame_serialize/CBORStream2Deserializer.cpp +++ b/frame_serialize/CBORStream2Deserializer.cpp @@ -687,6 +687,8 @@ namespace { message.refinement_time_s = GetCBORFloat(value); else if (key == "processing_time") message.processing_time_s = GetCBORFloat(value); + else if (key == "preprocessing_time") + message.preprocessing_time_s = GetCBORFloat(value); else if (key == "profile_radius") message.profile_radius = GetCBORFloat(value); else if (key == "mosaicity") diff --git a/frame_serialize/CBORStream2Serializer.cpp b/frame_serialize/CBORStream2Serializer.cpp index 1fc8902d..01f2b16c 100644 --- a/frame_serialize/CBORStream2Serializer.cpp +++ b/frame_serialize/CBORStream2Serializer.cpp @@ -709,6 +709,7 @@ void CBORStream2Serializer::SerializeImageInternal(CborEncoder &mapEncoder, cons CBOR_ENC(mapEncoder, "bragg_prediction_time", message.bragg_prediction_time_s); CBOR_ENC(mapEncoder, "integration_time", message.integration_time_s); CBOR_ENC(mapEncoder, "refinement_time", message.refinement_time_s); + CBOR_ENC(mapEncoder, "preprocessing_time", message.preprocessing_time_s); CBOR_ENC(mapEncoder, "indexing_unit_cell", message.indexing_unit_cell); CBOR_ENC(mapEncoder, "xfel_pulse_id", message.xfel_pulse_id); CBOR_ENC(mapEncoder, "xfel_event_code", message.xfel_event_code); diff --git a/image_analysis/MXAnalysisWithoutFPGA.cpp b/image_analysis/MXAnalysisWithoutFPGA.cpp index 4f0a4013..a892f81b 100644 --- a/image_analysis/MXAnalysisWithoutFPGA.cpp +++ b/image_analysis/MXAnalysisWithoutFPGA.cpp @@ -85,6 +85,7 @@ void MXAnalysisWithoutFPGA::Analyze(DataMessage &output, T sat_pixel_val, AzimuthalIntegrationProfile &profile, const SpotFindingSettings &settings) { + const auto preprocessing_start_time = std::chrono::steady_clock::now(); auto image = reinterpret_cast(in_image); std::vector roi(roi_count); @@ -152,6 +153,9 @@ void MXAnalysisWithoutFPGA::Analyze(DataMessage &output, } } + const auto preprocessing_end_time = std::chrono::steady_clock::now(); + output.preprocessing_time_s = std::chrono::duration(preprocessing_end_time - preprocessing_start_time).count(); + if (settings.enable) { // Update resolution mask if (mask_high_res != settings.high_resolution_limit diff --git a/receiver/JFJochReceiverFPGA.cpp b/receiver/JFJochReceiverFPGA.cpp index dcd446c2..5d0e3d2c 100644 --- a/receiver/JFJochReceiverFPGA.cpp +++ b/receiver/JFJochReceiverFPGA.cpp @@ -343,6 +343,8 @@ void JFJochReceiverFPGA::FrameTransformationThread(uint32_t threadid) { auto local_spot_finding_settings = GetSpotFindingSettings(); + const auto preprocessing_start_time = std::chrono::steady_clock::now(); + if (experiment.IsCPUSummation()) { std::vector> summation; for (int i = 0; i < experiment.GetModulesNum(); i++) @@ -409,6 +411,9 @@ void JFJochReceiverFPGA::FrameTransformationThread(uint32_t threadid) { message.receiver_aq_dev_delay = delay; } } + const auto preprocessing_end_time = std::chrono::steady_clock::now(); + message.preprocessing_time_s = std::chrono::duration(preprocessing_end_time - preprocessing_start_time).count(); + auto image_start_time = std::chrono::high_resolution_clock::now(); metadata.Export(message, expected_packets_per_image); diff --git a/receiver/JFJochReceiverPlots.cpp b/receiver/JFJochReceiverPlots.cpp index 8132ea4e..d7379cce 100644 --- a/receiver/JFJochReceiverPlots.cpp +++ b/receiver/JFJochReceiverPlots.cpp @@ -112,6 +112,7 @@ void JFJochReceiverPlots::Setup(const DiffractionExperiment &experiment, const A total_processing_time.Clear(r); indexing_time.Clear(r); bragg_prediction_time.Clear(r); + preprocessing_time.Clear(r); } void JFJochReceiverPlots::Add(const DataMessage &msg, const AzimuthalIntegrationProfile &profile) { @@ -140,6 +141,7 @@ void JFJochReceiverPlots::Add(const DataMessage &msg, const AzimuthalIntegration integration_time.AddElement(msg.number, msg.integration_time_s); refinement_time.AddElement(msg.number, msg.refinement_time_s); bragg_prediction_time.AddElement(msg.number, msg.bragg_prediction_time_s); + preprocessing_time.AddElement(msg.number, msg.preprocessing_time_s); if (msg.indexing_unit_cell) { indexing_uc_a.AddElement(msg.number, msg.indexing_unit_cell->a); @@ -340,25 +342,35 @@ MultiLinePlot JFJochReceiverPlots::GetPlots(const PlotRequest &request) { ret = pixel_sum.GetMeanPlot(nbins, start, incr, request.fill_value); break; case PlotType::ImageProcessingTime: { + auto preprocessing = preprocessing_time.GetMeanPerBin(nbins, start, incr, request.fill_value); + preprocessing.title = "preprocessing"; + if (!preprocessing.x.empty()) + ret.AddPlot(preprocessing); + auto spot_finding = spot_finding_time.GetMeanPerBin(nbins, start, incr, request.fill_value); spot_finding.title = "spot finding"; - ret.AddPlot(spot_finding); + if (!spot_finding.x.empty()) + ret.AddPlot(spot_finding); auto indexing = indexing_time.GetMeanPerBin(nbins, start, incr, request.fill_value); indexing.title = "indexing"; - ret.AddPlot(indexing); + if (!indexing.x.empty()) + ret.AddPlot(indexing); auto integration = integration_time.GetMeanPerBin(nbins, start, incr, request.fill_value); integration.title = "integration"; - ret.AddPlot(integration); + if (!integration.x.empty()) + ret.AddPlot(integration); auto refinement = refinement_time.GetMeanPerBin(nbins, start, incr, request.fill_value); refinement.title = "refinement"; - ret.AddPlot(refinement); + if (!refinement.x.empty()) + ret.AddPlot(refinement); auto bragg_prediction = bragg_prediction_time.GetMeanPerBin(nbins, start, incr, request.fill_value); bragg_prediction.title = "bragg prediction"; - ret.AddPlot(bragg_prediction); + if (!bragg_prediction.x.empty()) + ret.AddPlot(bragg_prediction); auto total = total_processing_time.GetMeanPerBin(nbins, start, incr, request.fill_value); total.title = "total"; @@ -409,6 +421,7 @@ MeanProcessingTime JFJochReceiverPlots::GetMeanProcessingTime() const { ret.refinement = refinement_time.Mean(); ret.bragg_prediction = bragg_prediction_time.Mean(); ret.processing = total_processing_time.Mean(); + ret.preprocessing = preprocessing_time.Mean(); return ret; } diff --git a/receiver/JFJochReceiverPlots.h b/receiver/JFJochReceiverPlots.h index f1171c5d..08c3a85e 100644 --- a/receiver/JFJochReceiverPlots.h +++ b/receiver/JFJochReceiverPlots.h @@ -25,6 +25,7 @@ struct MeanProcessingTime { float integration; float bragg_prediction; float processing; + float preprocessing; }; class JFJochReceiverPlots { @@ -91,6 +92,7 @@ class JFJochReceiverPlots { StatusVector integration_time; StatusVector bragg_prediction_time; StatusVector total_processing_time; + StatusVector preprocessing_time; MultiLinePlot GetROIPlot(PlotType type, int64_t nbins, float start, float incr, const std::optional &fill_value) const; diff --git a/tools/jfjoch_process.cpp b/tools/jfjoch_process.cpp index 081a6443..d08e45c6 100644 --- a/tools/jfjoch_process.cpp +++ b/tools/jfjoch_process.cpp @@ -766,7 +766,8 @@ int main(int argc, char **argv) { } auto image_mean_time = plots.GetMeanProcessingTime(); - logger.Info("Per-image time: (mean; microseconds): spot finding {:.0f} indexing {:.0f} refinement {:.0f} prediction {:.0f} integration {:.0f} total {:.0f}", + logger.Info("Per-image time: (mean; microseconds): preprocess {:.0f} spot finding {:.0f} indexing {:.0f} refinement {:.0f} prediction {:.0f} integration {:.0f} total {:.0f}", + image_mean_time.preprocessing * 1e6, image_mean_time.spot_finding * 1e6, image_mean_time.indexing * 1e6, image_mean_time.refinement * 1e6,