nhancdt2602 commented on issue #3515:
URL: https://github.com/apache/kvrocks/issues/3515#issuecomment-5015165747
@jihuayu I have a hypothesis about this flaky test. If it seems valid, I'd
be happy work on a fix.
### Hypothesis
I believe `TestSlaveLostMaster` occasionally fails with a connection reset
error because the connection is terminated with an RST packet instead of a FIN
packet. As a result, the proxy treats it as an unexpected error and calls
t.Fatalf, causing the test to fail.
```
n, err := src.Read(buf)
if err != nil {
if err == io.EOF {
break // clean close
}
log.Fatal(err) // or logger.Fatal / panic on unexpected error
}
```
`TestSlaveLostMaster` intentionally breaks the replication connection. It
first calls `cancelProxy()`, then issues SETNODES to point the replica to a
nonexistent master.
However, cancelling the proxy context does not immediately close the proxied
connections. The proxy only checks `ctx.Done()` between iterations of the copy
loop, so a goroutine blocked in `Read()` remains blocked even after the context
has been cancelled.
If the replica subsequently abandons replication and closes the socket in
the middle of a full sync while unread data is still queued in the receive
buffer, the kernel sends an RST instead of a FIN.
As a result, the blocked `Read()` returns `ECONNRESET` ("connection reset by
peer") instead of `io.EOF`. Since the proxy only treats `io.EOF` as an graceful
error, it considers the reset an unexpected error and calls `t.Fatalf`, causing
the test to fail.
### Timing diagram
For details, the timing scenario is as follows:
```
time test goroutine master→replica replica→master
replica (kvrocks)
──── ──────────────────────── ─────────────────────────
───────────────────────── ────────────────────────
t0 trigger full sync forwards SST firehose blocked in Read()
consumes SST stream,
(128 MB, throttled), (reads return instantly) (ack traffic is
sporadic) lagging the socket
sleep 2s │ │
│
t1 cancelProxy() ─────────► next select{} sees never reaches
select{} │
│ ctx.Done(); logs (only polled
BETWEEN │
│ "forwarding tcp stream reads) — stays
blocked │
│ stopped" [client.go:99]; in Read()
│
│ returns nil │
│
t2 SETNODES → nonexistent
──────────────────────────────────────────────────────► abandons replication;
master (127.0.0.2) │
close() with UNREAD
│ │
bytes in recv queue
│ │
→ kernel sends RST
t3 │ Read() ← RST:
returns (not FIN)
│ "connection reset
by peer"
│ │
t4 │ accept goroutine: errGrp.Wait() → err
│ → t.Fatalf [client.go:147] from a non-test
goroutine
t5 duration assertion
passes — but the test
has already FAILED
```
### Why it is flaky
Based on the CI history, this failure is intermittent because the ordering
of events is nondeterministic.
- The goroutine escapes before blocking. If even a single additional byte
(for example, a replication ACK) arrives after `cancelProxy()` is called,`
Read()` returns successfully, the copy loop completes the current iteration,
reaches the select, observes `ctx.Done()`, and exits cleanly. The test passes.
- FIN instead of RST. If the replica has already drained its receive buffer
before closing the socket, the kernel performs a graceful shutdown (FIN). In
that case, the blocked `Read()` returns `io.EOF`, which the proxy already
handles correctly, so the test passes.
In other words, whether the test fails depends on a race between proxy
cancellation, socket I/O, and the replica closing the connection.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
