Skip to content

feat(transfer): instrument writer.flush rate (INC_RECURSE I3)#4121

Merged
oferchen merged 3 commits into
masterfrom
feat/inc-recurse-flush-rate-2198
May 16, 2026
Merged

feat(transfer): instrument writer.flush rate (INC_RECURSE I3)#4121
oferchen merged 3 commits into
masterfrom
feat/inc-recurse-flush-rate-2198

Conversation

@oferchen
Copy link
Copy Markdown
Owner

Closes #2198

Summary

  • Adds a process-global AtomicU64 flush counter for the generator transfer hot path, bumped via a single flush_with_count() helper that replaces the five hot-path writer.flush() sites in run_transfer_loop() (per-iteration NDX flush, NDX_DONE flist-free echo, NDX_DONE phase-transition echo, dry-run per-file flush, final NDX_DONE goodbye).
  • Surfaces totals at end-of-transfer in GeneratorContext::run via flush_rate_totals(), emitting debug_log!(Send, 1, ...) plus a tracing::debug! event when the optional tracing feature is enabled. No CLI flag, no wire-format change, no public hot-path signature change.
  • Two unit tests: one asserts the counter increments by at least N after N flush_with_count calls (>= guards against concurrent test runs sharing the static), the other asserts that constructing a generator alone does not bump the counter.

Test plan

  • CI: fmt + clippy
  • CI: nextest (stable) - flush_with_count_increments_global_counter + flush_rate_totals_is_observable_without_flushing
  • CI: Windows / macOS / Linux musl

@oferchen oferchen force-pushed the feat/inc-recurse-flush-rate-2198 branch from d17bf31 to ea276f8 Compare May 16, 2026 03:42
oferchen added 3 commits May 16, 2026 07:51
Adds INC_RECURSE diagnostic counter I3 (#2198): a process-global
AtomicU64 that tracks every writer.flush() invocation on the generator
transfer hot path so operators can quantify flush-per-file and
flush-per-batch overhead under inc_recursive sends.

The counter is bumped from a single flush_with_count() helper, replacing
the five hot-path writer.flush() sites in run_transfer_loop():

- per-iteration flush before reading the next NDX request
- NDX_DONE echo on the INC_RECURSE flist-free path
- NDX_DONE echo on phase transitions
- per-file flush on the dry-run write path
- final NDX_DONE goodbye flush at end of loop

End-of-loop, end-of-transfer flushes outside the hot path (send_stats,
handle_goodbye, the pre-recv_filter_list flush in run()) are left
untouched - they fire at most once per transfer and would dilute the
per-file ratio.

Totals are sampled in GeneratorContext::run via flush_rate_totals() in
the same finalize block used by the I1 first-byte probe and emitted via:

- debug_log!(Send, 1, ...) for human output
- tracing::debug!(target = "rsync::generator::flush_rate", ...) when the
  optional tracing feature is enabled

Public API: a new flush_rate_totals() free function in the generator
module. No CLI flag, no wire-format change, no change to the existing
hot-path function signatures.

Two unit tests cover the counter behaviour:

- flush_with_count_increments_global_counter asserts the counter grows
  by at least N after N flush_with_count() calls (>= guards against
  concurrent test runs incrementing the shared counter)
- flush_rate_totals_is_observable_without_flushing asserts the counter
  does not move when only the snapshot reader is called, confirming
  constructing a generator does not bump the counter on its own

upstream: sender.c send_files() per-iteration io_flush before recv_ndx

Closes #2198
@oferchen oferchen force-pushed the feat/inc-recurse-flush-rate-2198 branch from ea276f8 to fc8e663 Compare May 16, 2026 04:51
@oferchen oferchen merged commit 28c4c17 into master May 16, 2026
39 checks passed
@oferchen oferchen deleted the feat/inc-recurse-flush-rate-2198 branch May 16, 2026 05:33
oferchen added a commit that referenced this pull request May 16, 2026
…4142)

* feat(transfer): instrument prepare_pending_acl cost (INC_RECURSE I5)

Adds INC_RECURSE diagnostic counter I5 (#2200): two process-global
AtomicU64 counters that track every prepare_pending_acl invocation on
the generator file-list path and the cumulative wall time spent inside
the helper across all generator transfers.

The counters fire from a single record_prepare_acl helper bumped from
prepare_pending_acl itself, which wraps the existing body in an
Instant::now() pair. The early-return path (entry.is_symlink() or
!flags.acls) is still counted so per-segment call rate stays comparable
to entry count, but contributes a near-zero ns delta.

Totals are sampled in GeneratorContext::run via prepare_acl_totals() in
the same finalize block used by PR #4103 (I1 first-byte latency),
PR #4120 (I4 NDX partition_point) and PR #4121 (I3 flush rate), and
emitted via:

- debug_log!(Genr, 1, "generator prepare_pending_acl totals: \
  calls=N elapsed_ns=M")
- tracing::debug! event on rsync::generator::prepare_acl when the
  optional tracing feature is enabled

Two unit tests in crates/transfer/src/generator/tests.rs cover the
new counters:

- prepare_acl_call_counter_increments asserts the call counter and the
  cumulative elapsed_ns counter grow by at least N and sum-of-durations
  after N synthetic record_prepare_acl invocations. The assertion uses
  >= because the counter is shared across the process and other tests
  may run concurrently.
- prepare_acl_totals_observable_without_prep asserts the totals
  snapshot is a pure read - constructing a generator does not bump the
  counter on its own, so two adjacent reads with no intervening prep
  call must return identical values.

No new CLI flag, no wire-format change, no change to the public
prepare_pending_acl signature.

Closes #2200

* fix(transfer): rewrap rustdoc list items for prepare_pending_acl counters
oferchen added a commit that referenced this pull request May 16, 2026
…RSE I2) (#4143)

Adds INC_RECURSE diagnostic counter I2 (#2197): two process-global
AtomicU64 counters that track every encode_and_send_segment invocation
on the generator file-list path and the cumulative wall time spent
inside the helper across all generator transfers.

The counters fire from a single record_segment_dispatch helper bumped
from encode_and_send_segment itself, which wraps the existing body in
an Instant::now() pair. The zero-entry early-return path is still
counted so per-transfer dispatch rate stays comparable to segment
scheduler activity, but contributes a near-zero ns delta.

Totals are sampled in GeneratorContext::run via
segment_dispatch_totals() in the same finalize block used by PR #4103
(I1 first-byte latency), PR #4120 (I4 NDX partition_point), PR #4121
(I3 flush rate) and PR #4142 (I5 prepare_pending_acl), and emitted
via:

- debug_log!(Genr, 1, "generator encode_and_send_segment totals: \
  calls=N elapsed_ns=M")
- tracing::debug! event on rsync::generator::segment_dispatch when
  the optional tracing feature is enabled

Two unit tests in crates/transfer/src/generator/tests.rs cover the
new counters:

- segment_dispatch_call_counter_increments asserts the call counter
  and the cumulative elapsed_ns counter grow by at least N and
  sum-of-durations after N synthetic record_segment_dispatch
  invocations. The assertion uses >= because the counter is shared
  across the process and other tests may run concurrently.
- segment_dispatch_totals_observable_without_dispatch asserts the
  totals snapshot is a pure read - constructing a generator does not
  bump the counter on its own, so two adjacent reads with no
  intervening dispatch call must return identical values.

No new CLI flag, no wire-format change, no change to the public
encode_and_send_segment signature.

Closes #2197
@oferchen oferchen mentioned this pull request May 16, 2026
oferchen added a commit that referenced this pull request May 18, 2026
* feat(transfer): instrument writer.flush rate (INC_RECURSE I3)

Adds INC_RECURSE diagnostic counter I3 (#2198): a process-global
AtomicU64 that tracks every writer.flush() invocation on the generator
transfer hot path so operators can quantify flush-per-file and
flush-per-batch overhead under inc_recursive sends.

The counter is bumped from a single flush_with_count() helper, replacing
the five hot-path writer.flush() sites in run_transfer_loop():

- per-iteration flush before reading the next NDX request
- NDX_DONE echo on the INC_RECURSE flist-free path
- NDX_DONE echo on phase transitions
- per-file flush on the dry-run write path
- final NDX_DONE goodbye flush at end of loop

End-of-loop, end-of-transfer flushes outside the hot path (send_stats,
handle_goodbye, the pre-recv_filter_list flush in run()) are left
untouched - they fire at most once per transfer and would dilute the
per-file ratio.

Totals are sampled in GeneratorContext::run via flush_rate_totals() in
the same finalize block used by the I1 first-byte probe and emitted via:

- debug_log!(Send, 1, ...) for human output
- tracing::debug!(target = "rsync::generator::flush_rate", ...) when the
  optional tracing feature is enabled

Public API: a new flush_rate_totals() free function in the generator
module. No CLI flag, no wire-format change, no change to the existing
hot-path function signatures.

Two unit tests cover the counter behaviour:

- flush_with_count_increments_global_counter asserts the counter grows
  by at least N after N flush_with_count() calls (>= guards against
  concurrent test runs incrementing the shared counter)
- flush_rate_totals_is_observable_without_flushing asserts the counter
  does not move when only the snapshot reader is called, confirming
  constructing a generator does not bump the counter on its own

upstream: sender.c send_files() per-iteration io_flush before recv_ndx

Closes #2198

* ci: trigger workflow

* ci: trigger workflow
oferchen added a commit that referenced this pull request May 18, 2026
…4142)

* feat(transfer): instrument prepare_pending_acl cost (INC_RECURSE I5)

Adds INC_RECURSE diagnostic counter I5 (#2200): two process-global
AtomicU64 counters that track every prepare_pending_acl invocation on
the generator file-list path and the cumulative wall time spent inside
the helper across all generator transfers.

The counters fire from a single record_prepare_acl helper bumped from
prepare_pending_acl itself, which wraps the existing body in an
Instant::now() pair. The early-return path (entry.is_symlink() or
!flags.acls) is still counted so per-segment call rate stays comparable
to entry count, but contributes a near-zero ns delta.

Totals are sampled in GeneratorContext::run via prepare_acl_totals() in
the same finalize block used by PR #4103 (I1 first-byte latency),
PR #4120 (I4 NDX partition_point) and PR #4121 (I3 flush rate), and
emitted via:

- debug_log!(Genr, 1, "generator prepare_pending_acl totals: \
  calls=N elapsed_ns=M")
- tracing::debug! event on rsync::generator::prepare_acl when the
  optional tracing feature is enabled

Two unit tests in crates/transfer/src/generator/tests.rs cover the
new counters:

- prepare_acl_call_counter_increments asserts the call counter and the
  cumulative elapsed_ns counter grow by at least N and sum-of-durations
  after N synthetic record_prepare_acl invocations. The assertion uses
  >= because the counter is shared across the process and other tests
  may run concurrently.
- prepare_acl_totals_observable_without_prep asserts the totals
  snapshot is a pure read - constructing a generator does not bump the
  counter on its own, so two adjacent reads with no intervening prep
  call must return identical values.

No new CLI flag, no wire-format change, no change to the public
prepare_pending_acl signature.

Closes #2200

* fix(transfer): rewrap rustdoc list items for prepare_pending_acl counters
oferchen added a commit that referenced this pull request May 18, 2026
…RSE I2) (#4143)

Adds INC_RECURSE diagnostic counter I2 (#2197): two process-global
AtomicU64 counters that track every encode_and_send_segment invocation
on the generator file-list path and the cumulative wall time spent
inside the helper across all generator transfers.

The counters fire from a single record_segment_dispatch helper bumped
from encode_and_send_segment itself, which wraps the existing body in
an Instant::now() pair. The zero-entry early-return path is still
counted so per-transfer dispatch rate stays comparable to segment
scheduler activity, but contributes a near-zero ns delta.

Totals are sampled in GeneratorContext::run via
segment_dispatch_totals() in the same finalize block used by PR #4103
(I1 first-byte latency), PR #4120 (I4 NDX partition_point), PR #4121
(I3 flush rate) and PR #4142 (I5 prepare_pending_acl), and emitted
via:

- debug_log!(Genr, 1, "generator encode_and_send_segment totals: \
  calls=N elapsed_ns=M")
- tracing::debug! event on rsync::generator::segment_dispatch when
  the optional tracing feature is enabled

Two unit tests in crates/transfer/src/generator/tests.rs cover the
new counters:

- segment_dispatch_call_counter_increments asserts the call counter
  and the cumulative elapsed_ns counter grow by at least N and
  sum-of-durations after N synthetic record_segment_dispatch
  invocations. The assertion uses >= because the counter is shared
  across the process and other tests may run concurrently.
- segment_dispatch_totals_observable_without_dispatch asserts the
  totals snapshot is a pure read - constructing a generator does not
  bump the counter on its own, so two adjacent reads with no
  intervening dispatch call must return identical values.

No new CLI flag, no wire-format change, no change to the public
encode_and_send_segment signature.

Closes #2197
oferchen added a commit that referenced this pull request May 18, 2026
* feat(transfer): instrument writer.flush rate (INC_RECURSE I3)

Adds INC_RECURSE diagnostic counter I3 (#2198): a process-global
AtomicU64 that tracks every writer.flush() invocation on the generator
transfer hot path so operators can quantify flush-per-file and
flush-per-batch overhead under inc_recursive sends.

The counter is bumped from a single flush_with_count() helper, replacing
the five hot-path writer.flush() sites in run_transfer_loop():

- per-iteration flush before reading the next NDX request
- NDX_DONE echo on the INC_RECURSE flist-free path
- NDX_DONE echo on phase transitions
- per-file flush on the dry-run write path
- final NDX_DONE goodbye flush at end of loop

End-of-loop, end-of-transfer flushes outside the hot path (send_stats,
handle_goodbye, the pre-recv_filter_list flush in run()) are left
untouched - they fire at most once per transfer and would dilute the
per-file ratio.

Totals are sampled in GeneratorContext::run via flush_rate_totals() in
the same finalize block used by the I1 first-byte probe and emitted via:

- debug_log!(Send, 1, ...) for human output
- tracing::debug!(target = "rsync::generator::flush_rate", ...) when the
  optional tracing feature is enabled

Public API: a new flush_rate_totals() free function in the generator
module. No CLI flag, no wire-format change, no change to the existing
hot-path function signatures.

Two unit tests cover the counter behaviour:

- flush_with_count_increments_global_counter asserts the counter grows
  by at least N after N flush_with_count() calls (>= guards against
  concurrent test runs incrementing the shared counter)
- flush_rate_totals_is_observable_without_flushing asserts the counter
  does not move when only the snapshot reader is called, confirming
  constructing a generator does not bump the counter on its own

upstream: sender.c send_files() per-iteration io_flush before recv_ndx

Closes #2198

* ci: trigger workflow

* ci: trigger workflow
oferchen added a commit that referenced this pull request May 18, 2026
…4142)

* feat(transfer): instrument prepare_pending_acl cost (INC_RECURSE I5)

Adds INC_RECURSE diagnostic counter I5 (#2200): two process-global
AtomicU64 counters that track every prepare_pending_acl invocation on
the generator file-list path and the cumulative wall time spent inside
the helper across all generator transfers.

The counters fire from a single record_prepare_acl helper bumped from
prepare_pending_acl itself, which wraps the existing body in an
Instant::now() pair. The early-return path (entry.is_symlink() or
!flags.acls) is still counted so per-segment call rate stays comparable
to entry count, but contributes a near-zero ns delta.

Totals are sampled in GeneratorContext::run via prepare_acl_totals() in
the same finalize block used by PR #4103 (I1 first-byte latency),
PR #4120 (I4 NDX partition_point) and PR #4121 (I3 flush rate), and
emitted via:

- debug_log!(Genr, 1, "generator prepare_pending_acl totals: \
  calls=N elapsed_ns=M")
- tracing::debug! event on rsync::generator::prepare_acl when the
  optional tracing feature is enabled

Two unit tests in crates/transfer/src/generator/tests.rs cover the
new counters:

- prepare_acl_call_counter_increments asserts the call counter and the
  cumulative elapsed_ns counter grow by at least N and sum-of-durations
  after N synthetic record_prepare_acl invocations. The assertion uses
  >= because the counter is shared across the process and other tests
  may run concurrently.
- prepare_acl_totals_observable_without_prep asserts the totals
  snapshot is a pure read - constructing a generator does not bump the
  counter on its own, so two adjacent reads with no intervening prep
  call must return identical values.

No new CLI flag, no wire-format change, no change to the public
prepare_pending_acl signature.

Closes #2200

* fix(transfer): rewrap rustdoc list items for prepare_pending_acl counters
oferchen added a commit that referenced this pull request May 18, 2026
…RSE I2) (#4143)

Adds INC_RECURSE diagnostic counter I2 (#2197): two process-global
AtomicU64 counters that track every encode_and_send_segment invocation
on the generator file-list path and the cumulative wall time spent
inside the helper across all generator transfers.

The counters fire from a single record_segment_dispatch helper bumped
from encode_and_send_segment itself, which wraps the existing body in
an Instant::now() pair. The zero-entry early-return path is still
counted so per-transfer dispatch rate stays comparable to segment
scheduler activity, but contributes a near-zero ns delta.

Totals are sampled in GeneratorContext::run via
segment_dispatch_totals() in the same finalize block used by PR #4103
(I1 first-byte latency), PR #4120 (I4 NDX partition_point), PR #4121
(I3 flush rate) and PR #4142 (I5 prepare_pending_acl), and emitted
via:

- debug_log!(Genr, 1, "generator encode_and_send_segment totals: \
  calls=N elapsed_ns=M")
- tracing::debug! event on rsync::generator::segment_dispatch when
  the optional tracing feature is enabled

Two unit tests in crates/transfer/src/generator/tests.rs cover the
new counters:

- segment_dispatch_call_counter_increments asserts the call counter
  and the cumulative elapsed_ns counter grow by at least N and
  sum-of-durations after N synthetic record_segment_dispatch
  invocations. The assertion uses >= because the counter is shared
  across the process and other tests may run concurrently.
- segment_dispatch_totals_observable_without_dispatch asserts the
  totals snapshot is a pure read - constructing a generator does not
  bump the counter on its own, so two adjacent reads with no
  intervening dispatch call must return identical values.

No new CLI flag, no wire-format change, no change to the public
encode_and_send_segment signature.

Closes #2197
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant