Skip to content

Fix completion-hang deadlock so all clients report BENCHMARK_DONE (#699)#699

Open
charles-typ wants to merge 1 commit into
facebookresearch:v2-betafrom
charles-typ:export-D110091576-to-v2-beta
Open

Fix completion-hang deadlock so all clients report BENCHMARK_DONE (#699)#699
charles-typ wants to merge 1 commit into
facebookresearch:v2-betafrom
charles-typ:export-D110091576-to-v2-beta

Conversation

@charles-typ

@charles-typ charles-typ commented Jun 29, 2026

Copy link
Copy Markdown
Contributor

Summary:

The distributed run never finalized cleanly: warmup completed (warmup_done=N) but benchmark_done stalled below num_clients (e.g. 13/16). Because the admin server only broadcasts ALL_DONE once benchmarkCompleteClients_ >= numExpectedClients_, the missing clients block EVERY client forever at waitForNotification(0), so the run is torn down with no clean client-side results (only server-aggregated metrics survive).

Root cause is a google::log_mutex/stdio deadlock, not a coroutine hang. gstack on a stuck client showed 48 of 189 threads blocked forever (futex abstime=0x0) on google::log_mutex inside LogMessage::Flush(); the lock holder was blocked in __libc_write(fd=1) to stdout, its buffer full of Benchmark GET error (sample 1/1000): mc_res_tko repeated. The stdout/stderr pipe to benchpress/automark was backpressured, so write() blocked while holding the stdio FILE lock and glog's log_mutex, wedging every logging thread including the coro worker event-base threads -> mainScope.joinAsync() never returns -> BENCHMARK_DONE is never sent. Under the mc_res_tko storm at multi-M QPS, even 1-in-1000 error sampling is thousands of synchronous prints/sec, which is enough to back the pipe up.

Fix: the four hot-path sampled error prints now fire only on the FIRST error per worker (errors == 1 instead of errors % 1000 == 1) -> at most one line per worker for the whole run, flood-proof, while keeping the error-type diagnostic (still gated by --verbose). The error counts themselves are unchanged and still reported at the end.

This change also folds in the related straggler-drain robustness the completion path needs: per-request co_await now uses folly::makePromiseContract + SemiFuture::within(10s) (global-timekeeper based, abandons the underlying future so the await always completes even if the McRouter callback never fires), and the warmup/measurement worker scopes use CancellableAsyncScope::cancelAndJoinAsync() to cancel rather than wait on requests still outstanding at window-end.

This entire diff stack contributed to the final result.

Reviewed By: excelle08

Differential Revision: D110091576

@meta-cla meta-cla Bot added the CLA Signed This label is managed by the Facebook bot. Authors need to sign the CLA before a PR can be reviewed. label Jun 29, 2026
@meta-codesync

meta-codesync Bot commented Jun 29, 2026

Copy link
Copy Markdown

@charles-typ has exported this pull request. If you are a Meta employee, you can view the originating Diff in D110091576.

@meta-codesync meta-codesync Bot changed the title Fix completion-hang deadlock so all clients report BENCHMARK_DONE Fix completion-hang deadlock so all clients report BENCHMARK_DONE (#699) Jul 2, 2026
@charles-typ charles-typ force-pushed the export-D110091576-to-v2-beta branch from b80922d to dd3d65e Compare July 2, 2026 18:12
charles-typ added a commit to charles-typ/DCPerf that referenced this pull request Jul 2, 2026
…cebookresearch#699)

Summary:

The distributed run never finalized cleanly: warmup completed (`warmup_done=N`) but `benchmark_done` stalled below `num_clients` (e.g. 13/16). Because the admin server only broadcasts `ALL_DONE` once `benchmarkCompleteClients_ >= numExpectedClients_`, the missing clients block EVERY client forever at `waitForNotification(0)`, so the run is torn down with no clean client-side results (only server-aggregated metrics survive).

Root cause is a `google::log_mutex`/stdio deadlock, not a coroutine hang. `gstack` on a stuck client showed 48 of 189 threads blocked forever (`futex abstime=0x0`) on `google::log_mutex` inside `LogMessage::Flush()`; the lock holder was blocked in `__libc_write(fd=1)` to stdout, its buffer full of `Benchmark GET error (sample 1/1000): mc_res_tko` repeated. The stdout/stderr pipe to benchpress/automark was backpressured, so `write()` blocked while holding the stdio FILE lock and glog's `log_mutex`, wedging every logging thread including the coro worker event-base threads -> `mainScope.joinAsync()` never returns -> `BENCHMARK_DONE` is never sent. Under the `mc_res_tko` storm at multi-M QPS, even 1-in-1000 error sampling is thousands of synchronous prints/sec, which is enough to back the pipe up.

Fix: the four hot-path sampled error prints now fire only on the FIRST error per worker (`errors == 1` instead of `errors % 1000 == 1`) -> at most one line per worker for the whole run, flood-proof, while keeping the error-type diagnostic (still gated by `--verbose`). The error counts themselves are unchanged and still reported at the end.

This change also folds in the related straggler-drain robustness the completion path needs: per-request `co_await` now uses `folly::makePromiseContract` + `SemiFuture::within(10s)` (global-timekeeper based, abandons the underlying future so the await always completes even if the McRouter callback never fires), and the warmup/measurement worker scopes use `CancellableAsyncScope::cancelAndJoinAsync()` to cancel rather than wait on requests still outstanding at window-end.

This entire diff stack contributed to the final result.

Differential Revision: D110091576
@charles-typ charles-typ force-pushed the export-D110091576-to-v2-beta branch from dd3d65e to 9ded98d Compare July 2, 2026 19:17
charles-typ added a commit to charles-typ/DCPerf that referenced this pull request Jul 2, 2026
…cebookresearch#699)

Summary:

The distributed run never finalized cleanly: warmup completed (`warmup_done=N`) but `benchmark_done` stalled below `num_clients` (e.g. 13/16). Because the admin server only broadcasts `ALL_DONE` once `benchmarkCompleteClients_ >= numExpectedClients_`, the missing clients block EVERY client forever at `waitForNotification(0)`, so the run is torn down with no clean client-side results (only server-aggregated metrics survive).

Root cause is a `google::log_mutex`/stdio deadlock, not a coroutine hang. `gstack` on a stuck client showed 48 of 189 threads blocked forever (`futex abstime=0x0`) on `google::log_mutex` inside `LogMessage::Flush()`; the lock holder was blocked in `__libc_write(fd=1)` to stdout, its buffer full of `Benchmark GET error (sample 1/1000): mc_res_tko` repeated. The stdout/stderr pipe to benchpress/automark was backpressured, so `write()` blocked while holding the stdio FILE lock and glog's `log_mutex`, wedging every logging thread including the coro worker event-base threads -> `mainScope.joinAsync()` never returns -> `BENCHMARK_DONE` is never sent. Under the `mc_res_tko` storm at multi-M QPS, even 1-in-1000 error sampling is thousands of synchronous prints/sec, which is enough to back the pipe up.

Fix: the four hot-path sampled error prints now fire only on the FIRST error per worker (`errors == 1` instead of `errors % 1000 == 1`) -> at most one line per worker for the whole run, flood-proof, while keeping the error-type diagnostic (still gated by `--verbose`). The error counts themselves are unchanged and still reported at the end.

This change also folds in the related straggler-drain robustness the completion path needs: per-request `co_await` now uses `folly::makePromiseContract` + `SemiFuture::within(10s)` (global-timekeeper based, abandons the underlying future so the await always completes even if the McRouter callback never fires), and the warmup/measurement worker scopes use `CancellableAsyncScope::cancelAndJoinAsync()` to cancel rather than wait on requests still outstanding at window-end.

This entire diff stack contributed to the final result.

Differential Revision: D110091576
…cebookresearch#699)

Summary:

The distributed run never finalized cleanly: warmup completed (`warmup_done=N`) but `benchmark_done` stalled below `num_clients` (e.g. 13/16). Because the admin server only broadcasts `ALL_DONE` once `benchmarkCompleteClients_ >= numExpectedClients_`, the missing clients block EVERY client forever at `waitForNotification(0)`, so the run is torn down with no clean client-side results (only server-aggregated metrics survive).

Root cause is a `google::log_mutex`/stdio deadlock, not a coroutine hang. `gstack` on a stuck client showed 48 of 189 threads blocked forever (`futex abstime=0x0`) on `google::log_mutex` inside `LogMessage::Flush()`; the lock holder was blocked in `__libc_write(fd=1)` to stdout, its buffer full of `Benchmark GET error (sample 1/1000): mc_res_tko` repeated. The stdout/stderr pipe to benchpress/automark was backpressured, so `write()` blocked while holding the stdio FILE lock and glog's `log_mutex`, wedging every logging thread including the coro worker event-base threads -> `mainScope.joinAsync()` never returns -> `BENCHMARK_DONE` is never sent. Under the `mc_res_tko` storm at multi-M QPS, even 1-in-1000 error sampling is thousands of synchronous prints/sec, which is enough to back the pipe up.

Fix: the four hot-path sampled error prints now fire only on the FIRST error per worker (`errors == 1` instead of `errors % 1000 == 1`) -> at most one line per worker for the whole run, flood-proof, while keeping the error-type diagnostic (still gated by `--verbose`). The error counts themselves are unchanged and still reported at the end.

This change also folds in the related straggler-drain robustness the completion path needs: per-request `co_await` now uses `folly::makePromiseContract` + `SemiFuture::within(10s)` (global-timekeeper based, abandons the underlying future so the await always completes even if the McRouter callback never fires), and the warmup/measurement worker scopes use `CancellableAsyncScope::cancelAndJoinAsync()` to cancel rather than wait on requests still outstanding at window-end.

This entire diff stack contributed to the final result.

Reviewed By: excelle08

Differential Revision: D110091576
@charles-typ charles-typ force-pushed the export-D110091576-to-v2-beta branch from 9ded98d to 82cd721 Compare July 6, 2026 18:03
meta-codesync Bot pushed a commit that referenced this pull request Jul 6, 2026
Summary:
Pull Request resolved: #699

The distributed run never finalized cleanly: warmup completed (`warmup_done=N`) but `benchmark_done` stalled below `num_clients` (e.g. 13/16). Because the admin server only broadcasts `ALL_DONE` once `benchmarkCompleteClients_ >= numExpectedClients_`, the missing clients block EVERY client forever at `waitForNotification(0)`, so the run is torn down with no clean client-side results (only server-aggregated metrics survive).

Root cause is a `google::log_mutex`/stdio deadlock, not a coroutine hang. `gstack` on a stuck client showed 48 of 189 threads blocked forever (`futex abstime=0x0`) on `google::log_mutex` inside `LogMessage::Flush()`; the lock holder was blocked in `__libc_write(fd=1)` to stdout, its buffer full of `Benchmark GET error (sample 1/1000): mc_res_tko` repeated. The stdout/stderr pipe to benchpress/automark was backpressured, so `write()` blocked while holding the stdio FILE lock and glog's `log_mutex`, wedging every logging thread including the coro worker event-base threads -> `mainScope.joinAsync()` never returns -> `BENCHMARK_DONE` is never sent. Under the `mc_res_tko` storm at multi-M QPS, even 1-in-1000 error sampling is thousands of synchronous prints/sec, which is enough to back the pipe up.

Fix: the four hot-path sampled error prints now fire only on the FIRST error per worker (`errors == 1` instead of `errors % 1000 == 1`) -> at most one line per worker for the whole run, flood-proof, while keeping the error-type diagnostic (still gated by `--verbose`). The error counts themselves are unchanged and still reported at the end.

This change also folds in the related straggler-drain robustness the completion path needs: per-request `co_await` now uses `folly::makePromiseContract` + `SemiFuture::within(10s)` (global-timekeeper based, abandons the underlying future so the await always completes even if the McRouter callback never fires), and the warmup/measurement worker scopes use `CancellableAsyncScope::cancelAndJoinAsync()` to cancel rather than wait on requests still outstanding at window-end.

This entire diff stack contributed to the final result.

Reviewed By: excelle08

Differential Revision: D110091576

fbshipit-source-id: e8df4ca630351daa8f48a91174c9401ca2e1138e
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

CLA Signed This label is managed by the Facebook bot. Authors need to sign the CLA before a PR can be reviewed. meta-exported

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant