Skip to content

sync: Summarize what a sync cycle reached - #496

Open
chucklever wants to merge 1 commit into
sashiko-dev:mainfrom
chucklever:sync-cycle-summary
Open

chucklever wants to merge 1 commit into
sashiko-dev:mainfrom
chucklever:sync-cycle-summary

Conversation

@chucklever

Copy link
Copy Markdown
Contributor

A sync cycle that reaches no remote at all closes with "Sync cycle
complete", the same line a healthy cycle writes. The per-remote
failures are in the journal, three lines each, but the state they add
up to is recorded nowhere. One minute of a network outage put 116
lines in the journal and named no condition.

Counting failed returns would not name it either. A fetch that fails
against a remote whose local ref is recent enough falls back to that
ref and returns success, which is the path most remotes take when the
network is down. So ensure_remote now reports what happened rather
than whether it succeeded, and the cycle closes on a count of those
outcomes.

Two choices in the diff are worth a look. A remote nothing went out
to, because its fetch interval had not elapsed or a recent failure is
backing off, is counted apart from the ones that answered. The backoff
used to return an error, which would have made the cycle after an
outage report every remote as failed on a network that had recovered.
And the fallback path carries git's message out with it, because a
cycle where every remote fell back has no failed return to quote.

A cycle that tries more than one remote and fetches none logs at error
with the first failure. One remote tried and lost is that remote's
condition, and its own line already names it.

Verified standalone on top of e38762e: sign-off valid, clippy
clean, 514 unit and 39 integration tests passing.

@rgushchin

Copy link
Copy Markdown
Member

Note

This review was prepared with the assistance of an AI code review pair.

Hi @chucklever, thanks for this PR! The motivation makes total sense—having the sync worker report a clean completion when network outages cause remotes to silently fall back to stale local refs can be very misleading in production.

During a detailed review of the diff, a few issues came up (including one security consideration regarding credential redaction) that would be great to address:


1. Security: Credential Sanitization in first_failure (src/worker/sync.rs)

In GitSyncWorker::run, first_failure captures raw git stderr from url_output.stderr, FetchOutcome::StaleLocalRef(message), and Err(e):

if first_failure.is_empty() {
    first_failure = message;
}

When git fetches fail against authenticated HTTPS remotes (e.g. URLs with embedded personal access tokens or passwords), git's stderr frequently echoes the remote URL with the embedded token in the error string.

In src/git_ops.rs and src/reviewer.rs, git error strings are passed through crate::utils::redact_secret(). We should do the same here before formatting into the summary log:

let sanitized_failure = crate::utils::redact_secret(&first_failure);

Additionally, git stderr often contains embedded newlines (fatal: ...\nerror: ...). Replacing newlines with spaces or semicolons when printing the summary line will prevent log-splitting / multi-line pollution in log aggregators that expect single-line events.


2. Single-Remote Setups Never Trigger Error Summary (tried > 1)

The error condition for the cycle summary is:

let tried = fetched + stale + failed;
if fetched == 0 && tried > 1 {
    error!(...);
} else {
    info!(...);
}

In default / single-remote installations (e.g. standard local setups tracking only origin in third_party/linux), tried can never exceed 1. If that single remote fails or falls back to stale refs, tried > 1 is never satisfied, and the worker will always log an info! level clean completion:

info!("GitSyncWorker: Sync cycle complete: 0 fetched, 0 skipped, 1 stale, 0 failed.")

Consider adjusting the condition to accommodate single-remote setups when failures occur, for example:

if fetched == 0 && tried > 0 && (tried > 1 || remotes.len() == 1) {

(Or logging at warn! if failed > 0 regardless of tried).


3. Cycle Health Oscillation: BackedOff Grouped into Skipped

In sync.rs:

Ok(FetchOutcome::Skipped) | Ok(FetchOutcome::BackedOff) => skipped += 1,
  • Skipped indicates a healthy remote whose sync interval has not yet elapsed.
  • BackedOff indicates the remote recently failed and is in a backoff cooldown.

Because BackedOff is grouped under skipped, tried (defined as fetched + stale + failed) does not count it. During a persistent outage:

  1. Cycle 1: Fetches fail/stale → logs error! with N stale / failed.
  2. Cycle 2 (1h later): All remotes are backed off → counted as skippedtried = 0, fetched = 0 → logs info!("... 0 fetched, N skipped, 0 stale, 0 failed.").

The worker oscillates between error alerts and completely clean green summaries every other cycle. Tracking backed_off as its own counter and including it in cycle health evaluation would prevent this flapping.


4. ensure_remote Returning Ok(BackedOff) When Local Ref Does Not Exist (src/git_ops.rs)

In src/git_ops.rs:

if !force_fetch && failed_recently(&repo_path, name).await? {
    info!("Skipping fetch for {} (backed off after recent failure)", name);
    return Ok(FetchOutcome::BackedOff);
}

// Check if HEAD exists
let head_ref = format!("refs/remotes/{}/HEAD", name);
let head_exists = ...;

failed_recently is checked before verifying head_exists. If a newly configured remote fails its very first fetch, it has no local ref. On subsequent non-forced calls, ensure_remote() returns Ok(FetchOutcome::BackedOff).

Other callers of ensure_remote (such as reviewer.rs:822) check if let Err(e) = ensure_remote(...). Because it now returns Ok, callers assume the remote is ready for use and proceed to query refs/remotes/{name}/HEAD, causing downstream failures with ambiguous argument errors.

ensure_remote should only return Ok(FetchOutcome::BackedOff) if head_exists is true; otherwise, if the local ref does not exist, it should return an Err.

A cycle that reaches no remote at all closes with "Sync cycle
complete", the same line a healthy cycle writes. The failures are
there, one per remote and three journal lines each, but the state they
add up to is recorded nowhere. One minute of a network outage, with
every fetch failing, put 116 lines in the journal and named no
condition.

Counting failed returns would not name it either. A fetch that fails
against a remote whose local ref is recent enough falls back to that
ref and returns success, which is the path most remotes take when the
network is down. Have ensure_remote report what happened, count the
outcomes, and close the cycle on them. A remote nothing went out to,
because its fetch interval had not elapsed or because a recent failure
is backing off, is counted apart from the ones that answered. The
backoff used to return an error, which counted a remote a review had
failed to fetch within the hour as failed on a network that had
recovered. It still returns one, of its own type, for a remote whose
local ref is missing or older than the fallback window, since that
remote has nothing for a caller to fall back on. The sync worker
counts that return as backing off, because nothing went out to the
remote. The fallback carries git's message out with it, because a
cycle where every remote fell back has no failed return to quote. A
remote whose URL cannot be read counts as failed, so the summary
reconciles with the number of remotes found.

A cycle that tries a remote and fetches none logs at error with the
first failure, so the state takes one line an hour rather than a
reader inferring it from the volume. A cycle can also find every
remote backing off and try nothing. The worker's own failures are an
hour old by its next cycle, past the backoff window, so those are
fetches a review or a baseline lookup failed within the hour. That is
the same outage, so it logs at warn rather than closing as a clean
cycle.

Signed-off-by: Chuck Lever <cel@kernel.org>
@chucklever

Copy link
Copy Markdown
Contributor Author

Fixed all four in the updated branch.

  1. The first failure now goes through redact_secret() with its lines joined into one, at the point it is captured. The per-remote lines in git_ops.rs log the same text unredacted and predate this PR; that is a separate change.
  2. The guard is now fetched == 0 && tried > 0. The remotes.len() == 1 form makes the level depend on the config rather than on what happened, and the plain form covers the single-remote case.
  3. BackedOff has its own counter, printed on every summary. A cycle where every remote is backing off has no failure to quote and the network may have recovered since, so it logs at warn as "fetched nothing" rather than at error or as a clean cycle.
  4. ensure_remote() checks for a usable local ref before honoring the backoff, and returns a typed BackoffError when there is none, so callers that only test is_err() bail as they did before this PR. The sync worker recognizes that error and counts the remote as backing off rather than failed. The backoff test now expects the error.

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.

2 participants