Skip to content

[release-3.6] fix: deflake TestIssue20271 - #22406

Merged
ahrtr merged 1 commit into
etcd-io:release-3.6from
silentred:fix-flaky-TestIssue20271
Sep 10, 2026
Merged

[release-3.6] fix: deflake TestIssue20271#22406
ahrtr merged 1 commit into
etcd-io:release-3.6from
silentred:fix-flaky-TestIssue20271

Conversation

@silentred

@silentred silentred commented Sep 9, 2026

Copy link
Copy Markdown
Member

Failed tests

Error logs:

=== FAIL: e2e TestIssue20271 (44.94s)  
    reproduce_20271_test.go:79: Step 5: After opening snapshot file from new leader, invoke defragment
    reproduce_20271_test.go:81: context done before matching log found: context deadline exceeded

Fail point:

e2e.AssertProcessLogs(t, epc.Procs[2], "applySnapshot: opened snapshot backend")

func AssertProcessLogs(t *testing.T, ep EtcdProcess, expectLog string) {
    t.Helper()
    var err error
    ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) 
    defer cancel()
    _, err = ep.Logs().ExpectWithContext(ctx, expect.ExpectedResponse{Value: expectLog})
    if err != nil {
        t.Fatal(err)
    }
}

Root cause: SIGSTOP doesn't drop packets

The mechanism. EtcdServerProcess.Pause() (tests/framework/e2e/etcd_process.go:280-288) only sends SIGSTOP —
it freezes the process but leaves the network stack alive, so the kernel keeps accepting and queueing inbound
data. Meanwhile the graceful restart path (Restart() → Stop() → SIGTERM → Close()) makes the peer see a TCP
FIN, not an RST. Under Linux semantics FIN does not discard data already sitting in the receiver's kernel
queue; only RST does.

The causal chain.

  1. All three members are level at index 55, then test-2 is SIGSTOP'd (02:58:34.800).
  2. test-0 (leader) + test-1 form a 2/3 quorum and commit/apply Step 3's 30 deletes up to index 88 — and the
    MsgApp(commit=88) is already written into test-2's kernel socket receive buffer.
  3. Step 4 gracefully restarts both test-0 and test-1; test-1's stop takes 8s (leadership transfer is
    impossible with only one healthy member), so the cluster has no quorum during that window.
  4. SIGCONT on test-2 at 02:58:43.858; within 4ms it drains the backlogged MsgApp and jumps applied 55→88.
    That's far too fast for a new election (≥1s election timeout), which proves the entries came from data
    already delivered to kernel buffers.

The consequence.

The new leader's raftLog has firstIndex=89 (snapshot@88), so it should have been forced to
send MsgSnap. But member 3 had already self-recovered to 88, so no snapshot transfer ever happens — and
"applySnapshot: opened snapshot backend" (server/etcdserver/server.go:1057), the log the test blocks on, is
never printed. AssertProcessLogs times out at 30s → t.Fatal.

Supporting evidence.

All snapshot-transfer log lines (sending/receiving/applied database snapshot, opened
snapshot backend, etc.) appear 0 times in the whole test block. skip compaction since there is an inflight
snapshot is also 0, meaning the compaction path itself was healthy — the fault isn't in compaction. The
asserted string and the applyAfterOpenSnapshot failpoint do exist in 3.6 code, so the assertion isn't simply
wrong.

/cc @ahrtr

@codecov

codecov Bot commented Sep 9, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 68.81%. Comparing base (4e6d3a9) to head (f637d17).
⚠️ Report is 1 commits behind head on release-3.6.

Additional details and impacted files

see 25 files with indirect coverage changes

@@               Coverage Diff               @@
##           release-3.6   #22406      +/-   ##
===============================================
- Coverage        68.84%   68.81%   -0.04%     
===============================================
  Files              420      420              
  Lines            35900    35900              
===============================================
- Hits             24716    24705      -11     
- Misses            9736     9751      +15     
+ Partials          1448     1444       -4     

Continue to review full report in Codecov by Harness.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 4e6d3a9...f637d17. Read the comment docs.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@silentred
silentred force-pushed the fix-flaky-TestIssue20271 branch from 0d3efaf to 0e8a10b Compare September 9, 2026 11:04
Comment thread tests/e2e/reproduce_20271_test.go Outdated
@silentred
silentred marked this pull request as draft September 9, 2026 16:17
@silentred
silentred force-pushed the fix-flaky-TestIssue20271 branch from 0e8a10b to ed1e62d Compare September 9, 2026 17:31
@kubernetes-prow kubernetes-prow Bot added size/S and removed size/XS labels Sep 9, 2026
@silentred
silentred marked this pull request as ready for review September 9, 2026 17:32
@silentred

Copy link
Copy Markdown
Member Author

ping @fuweid and @ahrtr

@ahrtr

ahrtr commented Sep 9, 2026

Copy link
Copy Markdown
Member

can you show us the PR indeed fix the flaky test, such as run the test 100 times on main and your dev branch separately?

go test -run TestIssue20271 -count 100 --failfast

@fuweid fuweid left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM thanks for working on this.

// member and replayed on resume. Writing more entries than the leader's
// inflight window can hold makes it stop replicating to that member, so it
// cannot catch up by itself and the new leader is forced to send a snapshot.
keyCount = 1024

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The change looks good to me. I run that 100 times without any error.
However, it's to use etcdctl for each operation. In my local, it takes 70 seconds for one round.
Maybe we can use client instead of etcdctl.

@silentred silentred Sep 10, 2026

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the help! I am going to run 100 times on current release-3.6 branch, and expect to see flaky errors.

I have a quick question and would love to get your opinion: Is it necessary to put 1024 keys in Step1? If I understand correctly, the key point is the write count in Step3. So the changes are as follows:

  • put small amount of data in Step1, via etcdctl
  • put 1024 keys in Step3, via etcd client

Maybe we can use client instead of etcdctl.

Done

@silentred silentred Sep 10, 2026

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have run go test ./e2e -run '^TestIssue20271$' -count=100 -v --failfast -timeout=600m > test-flaky.log 2>&1 on current release-3.6, and the test failed at 16th round.
I think the two experiments show that this PR is a valid fix. cc @ahrtr

    reproduce_20271_test.go:79: Step 5: After opening snapshot file from new leader, invoke defragment\n
        to override boltdb file. So, for the following changes, the third member will commit them into deleted boltdb file.
    reproduce_20271_test.go:81: context done before matching log found: context deadline exceeded
    logger.go:146: 2026-09-10T12:02:23.428+0800 INFO    closing test cluster...
    logger.go:146: 2026-09-10T12:02:23.428+0800 INFO    stopping server...      {"name": "TestIssue20271-test-0"}
    logger.go:146: 2026-09-10T12:02:23.548+0800 INFO    stopped server. {"name": "TestIssue20271-test-0"}
    logger.go:146: 2026-09-10T12:02:23.548+0800 INFO    stopping server...      {"name": "TestIssue20271-test-1"}
    logger.go:146: 2026-09-10T12:02:24.220+0800 INFO    stopped server. {"name": "TestIssue20271-test-1"}
    logger.go:146: 2026-09-10T12:02:24.220+0800 INFO    stopping server...      {"name": "TestIssue20271-test-2"}
    logger.go:146: 2026-09-10T12:02:24.244+0800 INFO    stopped server. {"name": "TestIssue20271-test-2"}
    logger.go:146: 2026-09-10T12:02:24.244+0800 INFO    closing server...       {"name": "TestIssue20271-test-0"}
    logger.go:146: 2026-09-10T12:02:24.244+0800 INFO    closing server...       {"name": "TestIssue20271-test-1"}
    logger.go:146: 2026-09-10T12:02:24.244+0800 INFO    closing server...       {"name": "TestIssue20271-test-2"}
    logger.go:146: 2026-09-10T12:02:24.244+0800 INFO    closed test cluster.
--- FAIL: TestIssue20271 (52.07s)
FAIL
FAIL    go.etcd.io/etcd/tests/v3/e2e    560.347s
FAIL

Signed-off-by: shenmu.wy <shenmu.wy@antfin.com>
@silentred
silentred force-pushed the fix-flaky-TestIssue20271 branch from ed1e62d to f637d17 Compare September 10, 2026 06:00

@ahrtr ahrtr left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM & thx

@kubernetes-prow

Copy link
Copy Markdown

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: ahrtr, fuweid, silentred

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Details Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@ahrtr
ahrtr merged commit c157222 into etcd-io:release-3.6 Sep 10, 2026
30 checks passed
@ahrtr

ahrtr commented Sep 10, 2026

Copy link
Copy Markdown
Member

/cherry-pick release-3.7

@ahrtr

ahrtr commented Sep 10, 2026

Copy link
Copy Markdown
Member

/cherry-pick release-3.6

@k8s-infra-cherrypick-robot

Copy link
Copy Markdown

@ahrtr: I cannot cherry-pick the present PR on top of its base branch (release-3.6).

Details

In response to this:

/cherry-pick release-3.6

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

@ahrtr

ahrtr commented Sep 10, 2026

Copy link
Copy Markdown
Member

/cherry-pick release-3.5

@k8s-infra-cherrypick-robot

Copy link
Copy Markdown

@ahrtr: #22406 failed to apply on top of branch "release-3.7":

Applying: fix: deflake TestIssue20271
Using index info to reconstruct a base tree...
M	tests/e2e/reproduce_20271_test.go
Falling back to patching base and 3-way merge...
Auto-merging tests/e2e/reproduce_20271_test.go
CONFLICT (content): Merge conflict in tests/e2e/reproduce_20271_test.go
error: Failed to merge in the changes.
hint: Use 'git am --show-current-patch=diff' to see the failed patch
hint: When you have resolved this problem, run "git am --continue".
hint: If you prefer to skip this patch, run "git am --skip" instead.
hint: To restore the original branch and stop patching, run "git am --abort".
hint: Disable this message with "git config set advice.mergeConflict false"
Patch failed at 0001 fix: deflake TestIssue20271

Details

In response to this:

/cherry-pick release-3.7

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

@k8s-infra-cherrypick-robot

Copy link
Copy Markdown

@ahrtr: #22406 failed to apply on top of branch "release-3.5":

Applying: fix: deflake TestIssue20271
Using index info to reconstruct a base tree...
M	tests/e2e/reproduce_20271_test.go
Falling back to patching base and 3-way merge...
Auto-merging tests/e2e/reproduce_20271_test.go
CONFLICT (content): Merge conflict in tests/e2e/reproduce_20271_test.go
error: Failed to merge in the changes.
hint: Use 'git am --show-current-patch=diff' to see the failed patch
hint: When you have resolved this problem, run "git am --continue".
hint: If you prefer to skip this patch, run "git am --skip" instead.
hint: To restore the original branch and stop patching, run "git am --abort".
hint: Disable this message with "git config set advice.mergeConflict false"
Patch failed at 0001 fix: deflake TestIssue20271

Details

In response to this:

/cherry-pick release-3.5

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

@ahrtr

ahrtr commented Sep 10, 2026

Copy link
Copy Markdown
Member

@silentred can you manually backport the fix to 3.7, 3.6 and 3.5 ? thx

@silentred

Copy link
Copy Markdown
Member Author

@silentred can you manually backport the fix to 3.7, 3.6 and 3.5 ? thx

Sure, I will issue PRs.

@fuweid fuweid changed the title fix: deflake TestIssue20271 [release-3.6] fix: deflake TestIssue20271 Sep 10, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Development

Successfully merging this pull request may close these issues.

4 participants