Fix completion-hang deadlock so all clients report BENCHMARK_DONE (#699)#699
Open
charles-typ wants to merge 1 commit into
Open
Fix completion-hang deadlock so all clients report BENCHMARK_DONE (#699)#699charles-typ wants to merge 1 commit into
charles-typ wants to merge 1 commit into
Conversation
|
@charles-typ has exported this pull request. If you are a Meta employee, you can view the originating Diff in D110091576. |
b80922d to
dd3d65e
Compare
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
dd3d65e to
9ded98d
Compare
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
9ded98d to
82cd721
Compare
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
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary:
The distributed run never finalized cleanly: warmup completed (
warmup_done=N) butbenchmark_donestalled belownum_clients(e.g. 13/16). Because the admin server only broadcastsALL_DONEoncebenchmarkCompleteClients_ >= numExpectedClients_, the missing clients block EVERY client forever atwaitForNotification(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.gstackon a stuck client showed 48 of 189 threads blocked forever (futex abstime=0x0) ongoogle::log_mutexinsideLogMessage::Flush(); the lock holder was blocked in__libc_write(fd=1)to stdout, its buffer full ofBenchmark GET error (sample 1/1000): mc_res_tkorepeated. The stdout/stderr pipe to benchpress/automark was backpressured, sowrite()blocked while holding the stdio FILE lock and glog'slog_mutex, wedging every logging thread including the coro worker event-base threads ->mainScope.joinAsync()never returns ->BENCHMARK_DONEis never sent. Under themc_res_tkostorm 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 == 1instead oferrors % 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_awaitnow usesfolly::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 useCancellableAsyncScope::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