Reduce ordinary compiled-pipeline completion polling latency

benchmark/results/perf_fast_poll_20260929/README.md

@@ -0,0 +1,31 @@
+# Compiled-pipeline completion polling: official30 1w_1t (2026-09-29)
+
+This report accompanies [OpenHCS issue #182](https://github.com/OpenHCSDev/openhcs/issues/182). It compares the [lazy-catalog fresh-server run](../perf_lazy_catalog_20260929/README.md) with the same CPU-only integration checkout and a 0.05-second polling interval for the two ordinary compile/execute completion waits. The control uses the inherited 0.5-second interval. Each observation starts and stops its own ZMQ server; `total_seconds` includes that lifecycle. The 1w_1t mode uses one well and one OpenHCS thread.
+
+All 30 cases succeeded. Twenty-six had a lower total, with a paired median saving of 0.354 seconds. All 110 files under the produced `results` directories were byte-identical to the control.
+
+| Sum over 30 observations (seconds) | 0.5-second control | 0.05-second candidate | Difference |
+| --- | ---: | ---: | ---: |
+| Server compilation jobs | 83.759 | 83.733 | -0.026 |
+| Server execution jobs | 89.219 | 90.693 | +1.474 |
+| Other measured time (`total - compile - execute`) | 101.289 | 88.948 | -12.341 |
+| Per-observation total | 274.266 | 263.374 | **-10.892** |
+| Client wait minus server-job time, from retained receipts | 13.827 | 1.554 | **-12.273** |
+
+The remaining `total_seconds` gain is consistent with faster detection of completed jobs. The +1.474-second server-execution difference could be workload variation or extra status-request contention, so it is reported separately and is not an execution-only gain. The full CLI wall time was 296.684 seconds for the control and 285.686 seconds for the candidate; this includes source preparation outside per-observation timers. The native CP total-phase reference sums to 1,319.357 seconds, and its 5× line is 263.871 seconds. The candidate per-observation sum is 0.497 seconds below that line. CP and OpenHCS total timers have different preparation boundaries, so this is an indicative reference, not a directly equivalent ratio.
+
+![Total time and completion-detection slack](polling_total_and_slack.png)
+
+The `wait_breakdown.csv` derives each case's `WAIT_OPENHCS` and server-job durations from its retained measured-run receipt. `plot.py` regenerates the figure from that CSV, the candidate CSV, and the existing control and native summary. The raw candidate run is in `/home/ts/code/projects/openhcs-benchmark-runs/perf-fast-poll-full-20260929`; the prior control run is in `/home/ts/code/projects/openhcs-benchmark-runs/perf-lazy-catalog-full-20260929`.
+
+Validation: 80 focused unit and integration tests passed on the patched path. The measured run used the ordinary ZMQ outcome and progress evidence path. The experiment changes only completion polling latency; it does not claim a faster pipeline execution algorithm. An event-driven completion signal in `zmqruntime` could remove residual wait slack and status requests, but the measured remaining direct payoff is only about 1.55 seconds across official30.
+
+Fresh benchmark command:
+
+```bash
+OPENHCS_CPU_ONLY=true .venv/bin/python scripts/benchmark_cppipe_well_throughput.py \
+  --manifest benchmark/manifests/official30_portable_axis1.json \
+  --output-dir /path/to/output \
+  --native-summary-csv benchmark/results/perf_lazy_catalog_20260929/native_cp_summary.csv \
+  --mode 1w_1t
+```

benchmark/results/perf_fast_poll_20260929/fast_poll_well_throughput.csv

@@ -0,0 +1,31 @@
+case_name,mode_name,worker_count,well_count,compile_seconds,prepare_seconds,execute_seconds,total_seconds,wells_per_second,successful_wells,native_single_sample_execution_seconds,projected_native_execution_seconds,projected_execution_speedup,peak_memory_mb,status,memory_limit_mb,error_message,execution_route,server_lifecycle,run_input_sha256
+ExampleColocalization,1w_1t,1,1,3.3101065158843994,0.0,3.844163656234741,10.263778779190034,0.26013460649057646,1,37.035618890076876,37.035618890076876,9.634246146105108,1315.40234375,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleCometAssay,1w_1t,1,1,3.035510778427124,0.0,2.5314300060272217,8.556119349785149,0.39503363617364284,1,13.304211451206356,13.304211451206356,5.255611025993065,1216.515625,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleFly,1w_1t,1,1,2.9934492111206055,0.0,2.1602623462677,8.249891720246524,0.4629067398817124,1,8.094948755111545,8.094948755111545,3.747206337738212,920.05078125,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleFlyURL,1w_1t,1,1,2.683825969696045,0.0,1.1354057788848877,6.841715413145721,0.8807423906034076,1,4.900778113398701,4.900778113398701,4.316323031411629,829.07421875,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleHuman,1w_1t,1,1,2.628810167312622,0.0,1.2092616558074951,6.777371522039175,0.8269508879219702,1,4.420192994643003,4.420192994643003,3.6552825217065035,798.6328125,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleIlluminationCorrection_Example1_AllMethod,1w_1t,1,1,2.5782742500305176,0.0,2.810371160507202,8.08219988225028,0.3558248867809777,1,946.6214662808925,946.6214662808925,336.83147606384165,1276.7109375,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleIlluminationCorrection_Example1_EachMethod,1w_1t,1,1,2.4493072032928467,0.0,0.16939973831176758,5.245963773224503,5.903196840597089,1,4.54475614009425,4.54475614009425,26.8285900874886,760.13671875,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleIlluminationCorrection_Example2,1w_1t,1,1,2.9007842540740967,0.0,1.7746107578277588,7.465981120243669,0.5635038532190948,1,48.04419008316472,48.04419008316472,27.073086236653943,1001.73828125,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleIlluminationCorrection_Example3,1w_1t,1,1,2.9183850288391113,0.0,0.874875545501709,6.64416542602703,1.1430197187950164,1,2.1520505752414465,2.1520505752414465,2.4598362433451313,793.23828125,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleImagingFlowCytometryObjectsInGrid,1w_1t,1,1,3.4344255924224854,0.0,21.618332862854004,28.388432712759823,0.04625703593075226,1,61.60158259188756,61.60158259188756,2.849506619344146,2424.79296875,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleNeighbors,1w_1t,1,1,2.460543394088745,0.0,1.3759188652038574,6.625465746037662,0.726787040493001,1,4.5466188420541584,4.5466188420541584,3.3044236524662574,850.32421875,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExamplePercentPositive,1w_1t,1,1,2.465564727783203,0.0,0.5546884536743164,5.9790011420845985,1.8028138018303639,1,2.5050158216618,2.5050158216618,4.516077097095322,799.81640625,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleSpeckles,1w_1t,1,1,2.3139264583587646,0.0,0.8206939697265625,5.890974103007466,1.2184809891233614,1,3.179383432958275,3.179383432958275,3.874018270193428,900.796875,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleTrackObjects,1w_1t,1,1,2.435426712036133,0.0,3.601717233657837,8.903016267344356,0.2776453383555651,1,9.587221414782107,9.587221414782107,2.6618473335968975,1580.0390625,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleTumor,1w_1t,1,1,2.2887659072875977,0.0,0.8129324913024902,5.926819425076246,1.2301144445558916,1,4.360487373080105,4.360487373080105,5.363898502929412,954.09375,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleUntangleAndStraightenWorms,1w_1t,1,1,3.0009536743164062,0.0,1.238189935684204,7.2066797418519855,0.8076305348479641,1,3.4416790287941694,3.4416790287941694,2.7796050748000565,861.53125,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleUntangleWorms,1w_1t,1,1,3.0912106037139893,0.0,2.188098192214966,8.335689563304186,0.4570178813537253,1,4.618807300925255,4.618807300925255,2.110877527049978,905.7265625,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleUntangleWormsBrightField,1w_1t,1,1,3.200813055038452,0.0,3.727550506591797,10.005470647942275,0.26827268959376965,1,7.377188352867961,7.377188352867961,1.9790981610637195,1023.86328125,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleVitra,1w_1t,1,1,2.891615390777588,0.0,1.3642120361328125,7.195859033148736,0.7330238800961915,1,4.122247557155788,4.122247557155788,3.0217058990633827,935.5390625,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleWoundHealing,1w_1t,1,1,2.0344831943511963,0.0,1.6444566249847412,6.3499644552357495,0.6081036038328338,1,4.702593941241503,4.702593941241503,2.8596643230314074,1206.03515625,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleYeastColonies,1w_1t,1,1,3.20620059967041,0.0,2.0971145629882812,8.346837885212153,0.476845670546034,1,12.096297012176365,12.096297012176365,5.768066859895226,1150.30859375,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+ExampleYeastPatches,1w_1t,1,1,3.3224527835845947,0.0,2.514336585998535,8.878206667955965,0.3977192256472947,1,5.990533472970128,5.990533472970128,2.3825503340838785,1083.046875,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+cp_tutorial_3d_monolayer,1w_1t,1,1,3.571105480194092,0.0,10.493359327316284,17.35563250305131,0.09529836621498348,1,14.058660756796598,14.058660756796598,1.339767401293419,1422.63671875,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+cp_tutorial_advanced_segmentation_final,1w_1t,1,1,4.244936466217041,0.0,10.715682983398438,18.60752471210435,0.09332116315397508,1,36.253466514870524,36.253466514870524,3.3832156635314043,1101.30859375,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+cp_tutorial_quality_control,1w_1t,1,1,2.0106170177459717,0.0,0.6097266674041748,5.53759868722409,1.640079159170385,1,4.787729676347226,4.787729676347226,7.852255661918658,809.171875,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+cp_tutorial_beginner_segmentation_final,1w_1t,1,1,3.1879985332489014,0.0,6.741356611251831,13.219823073130101,0.14833809538141401,1,16.074153264053166,16.074153264053166,2.384409280058586,967.34375,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+cp_tutorial_pixel_based_classification,1w_1t,1,1,2.392631769180298,0.0,0.8176169395446777,6.0282009481452405,1.223066636262318,1,4.208680049050599,4.208680049050599,5.147496150696644,990.828125,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+cp_tutorial_translocation_final,1w_1t,1,1,2.5957834720611572,0.0,0.8361177444458008,6.443194939754903,1.196003800472892,1,3.004684013314545,3.004684013314545,3.5936134991443374,879.9453125,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+cp4_supplement_combine_objects,1w_1t,1,1,2.006458282470703,0.0,0.15198445320129395,5.0026285741478205,6.579620342322529,1,1.8334413380362093,1.8334413380362093,12.063347924198078,776.1640625,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8
+cp_tutorial_translocation_start,1w_1t,1,1,2.078247547149658,0.0,0.2592785358428955,5.020165450870991,3.8568560901081663,1,2.1760300607420504,2.1760300607420504,8.39263479203142,802.56640625,success,,,ordinary-zmq-outcomes-v1,fresh-per-observation,414b6abaecd5d65e0076adbed7fa674a45931b71fe70435f7da7fc64565752e8

benchmark/results/perf_fast_poll_20260929/plot.py

@@ -0,0 +1,99 @@
+"""Rebuild the fresh-server completion-poll comparison figure."""
+
+from __future__ import annotations
+
+import csv
+from pathlib import Path
+
+import matplotlib.pyplot as plt
+
+HERE = Path(__file__).resolve().parent
+BASELINE = HERE.parent / "perf_lazy_catalog_20260929" / "lazy_fresh.csv"
+FAST = HERE / "fast_poll_well_throughput.csv"
+WAITS = HERE / "wait_breakdown.csv"
+NATIVE = HERE.parent / "perf_lazy_catalog_20260929" / "native_cp_summary.csv"
+
+
+def read_rows(path: Path) -> list[dict[str, str]]:
+    with path.open(newline="") as file:
+        return list(csv.DictReader(file))
+
+
+def total(rows: list[dict[str, str]], column: str) -> float:
+    return sum(float(row[column]) for row in rows)
+
+
+def main() -> None:
+    baseline = read_rows(BASELINE)
+    fast = read_rows(FAST)
+    waits = read_rows(WAITS)
+    native = read_rows(NATIVE)
+    assert {row["case_name"] for row in baseline} == {row["case_name"] for row in fast}
+    assert len(baseline) == len(fast) == len(waits) == 30
+
+    stacks = []
+    for rows in (baseline, fast):
+        compile_time = total(rows, "compile_seconds")
+        execution_time = total(rows, "execute_seconds")
+        other = total(rows, "total_seconds") - compile_time - execution_time
+        stacks.append((compile_time, execution_time, other))
+
+    native_total = total(native, "median_native_total_phase_seconds") / 5
+    fig, (ax, slack_ax) = plt.subplots(
+        1, 2, figsize=(11, 5), gridspec_kw={"width_ratios": [1.35, 1]}
+    )
+    colors = ("#6789a7", "#3a6f91", "#d19b59")
+    labels = ("Server compilation", "Server execution", "Other measured time")
+    for i, (components, title) in enumerate(
+        zip(stacks, ("0.5 s polling", "0.05 s polling"), strict=True)
+    ):
+        bottom = 0.0
+        for component, label, color in zip(components, labels, colors, strict=True):
+            ax.bar(
+                i,
+                component,
+                bottom=bottom,
+                color=color,
+                label=label if i == 0 else None,
+            )
+            bottom += component
+        ax.text(i, bottom + 2, f"{bottom:.1f}s", ha="center", fontsize=10)
+    ax.axhline(native_total, color="#665b83", linestyle="--", linewidth=1.5)
+    ax.text(
+        1.48,
+        native_total - 13,
+        f"Native CP / 5: {native_total:.1f}s",
+        ha="right",
+        fontsize=8,
+    )
+    ax.set_xticks([0, 1], ["0.5 s polling", "0.05 s polling"])
+    ax.set_ylim(0, 320)
+    ax.set_ylabel("Sum across 30 fresh-server observations (s)")
+    ax.set_title("Total measured time")
+    ax.legend(loc="lower center", bbox_to_anchor=(0.5, -0.25), ncol=3, fontsize=8)
+
+    slack = [
+        sum(
+            float(row[f"{label}_wait_seconds"])
+            - float(row[f"{label}_server_jobs_seconds"])
+            for row in waits
+        )
+        for label in ("baseline", "fast")
+    ]
+    bars = slack_ax.bar([0, 1], slack, color=["#d19b59", "#3a6f91"], width=0.6)
+    for bar, value in zip(bars, slack, strict=True):
+        slack_ax.text(
+            bar.get_x() + bar.get_width() / 2, value + 0.3, f"{value:.2f}s", ha="center"
+        )
+    slack_ax.set_xticks([0, 1], ["0.5 s polling", "0.05 s polling"])
+    slack_ax.set_ylim(0, 16)
+    slack_ax.set_ylabel("Client wait minus server job duration (s)")
+    slack_ax.set_title("Completion-detection slack")
+    fig.suptitle("Official30 CPU-only 1w_1t: ordinary compiled-pipeline waits")
+    fig.tight_layout()
+    fig.savefig(HERE / "polling_total_and_slack.png", dpi=180)
+    plt.close(fig)
+
+
+if __name__ == "__main__":
+    main()

benchmark/results/perf_fast_poll_20260929/wait_breakdown.csv

@@ -0,0 +1,31 @@
+case_name,baseline_wait_seconds,baseline_server_jobs_seconds,fast_wait_seconds,fast_server_jobs_seconds
+ExampleColocalization,7.458973863627762,6.971804141998291,7.183346257079393,7.154270172119141
+ExampleCometAssay,5.775292431004345,5.588053226470947,5.628505366388708,5.566940784454346
+ExampleFly,5.800650177989155,5.160991430282593,5.209190128836781,5.153711557388306
+ExampleFlyURL,4.10841123200953,3.727818727493286,3.872411630116403,3.8192317485809326
+ExampleHuman,4.568803396075964,3.8546557426452637,3.8820209708064795,3.838071823120117
+ExampleIlluminationCorrection_Example1_AllMethod,5.6383416866883636,5.277345180511475,5.416271521244198,5.38864541053772
+ExampleIlluminationCorrection_Example1_EachMethod,3.0766169033013284,2.621954917907715,2.6584986713714898,2.6187069416046143
+ExampleIlluminationCorrection_Example2,5.088365746196359,4.675433874130249,4.688320747110993,4.6753950119018555
+ExampleIlluminationCorrection_Example3,4.1549204853363335,3.799920082092285,3.8466997016221285,3.7932605743408203
+ExampleImagingFlowCytometryObjectsInGrid,24.878548303619027,24.631866693496704,25.122180372010916,25.05275845527649
+ExampleNeighbors,4.077288782224059,3.7803969383239746,3.8659362476319075,3.8364622592926025
+ExamplePercentPositive,3.2204895354807377,2.8722169399261475,3.1132358335889876,3.0202531814575195
+ExampleSpeckles,3.6545920688658953,3.145731210708618,3.2000916688703,3.134620428085327
+ExampleTrackObjects,6.086732611991465,5.652193069458008,6.109515583142638,6.03714394569397
+ExampleTumor,3.5489941192790866,3.1012332439422607,3.159094935748726,3.101698398590088
+ExampleUntangleAndStraightenWorms,4.637174046598375,4.248164653778076,4.2648476851172745,4.23914361000061
+ExampleUntangleWorms,5.870146865956485,5.406447410583496,5.343424811493605,5.279308795928955
+ExampleUntangleWormsBrightField,7.731790717225522,7.032237768173218,6.983187755569816,6.928363561630249
+ExampleVitra,4.6149715930223465,4.151696681976318,4.287284792866558,4.2558274269104
+ExampleWoundHealing,3.6667584315873682,3.48883056640625,3.7486501671373844,3.6789398193359375
+ExampleYeastColonies,6.276017351541668,5.319963693618774,5.3627080311998725,5.303315162658691
+ExampleYeastPatches,6.674209529999644,5.8515942096710205,5.877112004905939,5.83678936958313
+cp4_supplement_combine_objects,2.586142251268029,2.160597324371338,2.2017467822879553,2.158442735671997
+cp_tutorial_3d_monolayer,13.77482473757118,13.714367389678955,14.104768510442227,14.064464807510376
+cp_tutorial_advanced_segmentation_final,16.04488993808627,15.206478595733643,14.99068406643346,14.960619449615479
+cp_tutorial_beginner_segmentation_final,10.774854160379618,9.940781831741333,9.997978130821139,9.929355144500732
+cp_tutorial_pixel_based_classification,3.5643112482503057,3.1968584060668945,3.2659096368588507,3.2102487087249756
+cp_tutorial_quality_control,3.1354477154091,2.5399677753448486,2.6483420259319246,2.6203436851501465
+cp_tutorial_translocation_final,3.715478392317891,3.5193140506744385,3.52000420819968,3.431901216506958
+cp_tutorial_translocation_start,2.6000353237614036,2.338603973388672,2.4278075890615582,2.3375260829925537