almostintuitive opened a new issue, #4436:
URL: https://github.com/apache/iggy/issues/4436
## Bug description
In a cluster, a Rust SDK producer that writes to several partitions of one
topic
stalls for about 4 seconds on nearly every send once those partitions'
primaries
are on different nodes. Each send moves the client's only connection to
another
node.
Each partition is its own consensus group and elects its own primary. On a
fresh
cluster all partition primaries are on one node, so every send is admitted
where
the client is connected. After failovers (for example, nodes restarted one
at a
time) the primaries end up on different nodes. Polls handle this:
`PollRouter`
(`core/sdk/src/poll_routing.rs`) sends a poll to the partition's primary
over a
separate data connection and keeps the session where it is. Sends have no
equivalent. `SendMessages` goes out on the one TCP session:
1. The client is on node A. It sends to partition 0, whose primary is node B.
Node A's replica is a backup, so it refuses the request with
`TransientNotAccepted` (never admitted).
2. `send_raw_vsr_attempt` replays the refusal on the same connection every
50 ms
until `TRANSIENT_FAILOVER_CHECK_INTERVAL` (2 s) expires.
3. `send_raw_retaining_header` then takes `routing_lock` and `continue`s
("a concurrent refused request may have moved the shared client"), so a
second 2 s replay window runs on the same node.
4. Only then does it check the metadata leader, walk the roster
(`RosterWalk`, `settle_on_endpoint`), disconnect, and reconnect and sign
in
on the next node. The send succeeds there.
5. The next send goes to partition 1, whose primary is node A. Steps 1-4
repeat
in the other direction: 4 s of refusals on node B, then a redirect back to
the metadata leader.
A producer that spreads its sends over the partitions with
`Partitioning::messages_key(..)` or explicit partition ids hits this on
almost
every send. Throughput is capped by the 4 s stall, not by the server, and the
server sits nearly idle.
**Expected:** a send reaches its partition's primary without the session
moving
on every send, the way polls already do. Once the primaries are known, a
producer alternating between partitions should pay no refusal window and no
reconnect.
**Actual:** every send to a partition whose primary is not the connected node
waits out two transient windows (about 4 s), then moves the session. With
two or
more primaries in play this happens on nearly every send.
## Affected area / component
Rust SDK, Clustering / replication
## Deployment
Compiled from source
## Versions
- Rust SDK `iggy` 0.11.0 (released) against a 3-node cluster built from
`f6dfbdbb3` with unrelated patches: observed (numbers below).
- `master` @ `43fb44364`: failing integration test (PR linked below), 3 of 3
runs.
- Tag `iggy-0.11.0` (`71f29618b`): the same test fails the same way.
The Go SDK (`foreign/go`) looks the same from reading the code, but I didn't
run it. `SendMessages` resolves the partition client side and then goes
through
`c.do`. On `ErrTransientNotAccepted` that replays for `failoverCheckInterval`
(2 s), redirects to the leader or walks the roster with
`settleOnNextEndpoint`, and reconnects. There is no primary routing for
sends.
## Hardware / environment
- Observed: 3-node cluster on Kubernetes, 2 CPU / 8 GiB per node. 12
producers,
batches of 100 messages, 45k msg/s offered.
- Reproduced: the integration harness (3 nodes on localhost) in a Linux
x86_64
container (4 CPUs), pinned toolchain from `rust-toolchain.toml`.
## Reproduction
A failing test is on branch `test/sdk-send-partition-primary-routing` (PR
linked below). It is `#[ignore]`d with this issue's number, so run it with
`--ignored`:
```bash
cargo build --bin iggy-server
cargo test -p integration --test mod -- --ignored --exact \
cluster::partition_primary_routing::given_partitions_on_different_primaries_when_sending_round_robin_should_keep_the_session
```
It uses the existing `seed_split_primaries` fixture in
`core/integration/tests/cluster/partition_primary_routing.rs`. Partition 0
stays
on its primary while a metadata-only election moves the metadata leader. It
then
adds partition 1 with `create_partitions`. A partition created after the
election is seeded from the metadata view, so its primary is the metadata
leader.
The test checks this precondition with `GET_POLL_ROUTING`: the two partitions
report primaries on different nodes. It sends one warm-up message to each
partition. Then it sends 4 messages alternating between partitions 0 and 1,
and
asserts that no send moves the session to another node.
## Logs
The test's failure on master (partition, node before, node after, send time):
```text
assertion `left == right` failed: a producer alternating between partition 0
(primary node 0) and partition 1 (primary node 2) must keep its session; 4 of 4
sends moved it to another node (partition, from node, to node, send time):
[(0, 2, 0, 4.020694671s), (1, 0, 2, 4.018801233s), (0, 2, 0, 4.019829788s),
(1, 0, 2, 4.018055753s)]
```
The client log during that run, one send per pair of lines (node 2 at
`:20016`
is the metadata leader and partition 1's primary, node 0 at `:20000` is
partition 0's primary):
```text
20:54:02.365 iggy::tcp::tcp_client: The request keeps being refused on
127.0.0.1:20016 while the roster names it the metadata leader; trying the next
cluster node at 127.0.0.1:20000.
20:54:06.390 iggy::tcp::tcp_client: Current node is not leader, redirecting
to leader at: 127.0.0.1:20016
20:54:10.408 iggy::tcp::tcp_client: The request keeps being refused on
127.0.0.1:20016 while the roster names it the metadata leader; trying the next
cluster node at 127.0.0.1:20000.
20:54:14.428 iggy::tcp::tcp_client: Current node is not leader, redirecting
to leader at: 127.0.0.1:20016
```
Tag `iggy-0.11.0` gives the same pattern: `[(0, 2, 0, 4.068s), (1, 0, 2,
4.071s), (0, 2, 0, 4.081s), (1, 0, 2, 4.078s)]`.
Observed on the real cluster (SDK 0.11.0, 12 producers, batches of 100,
45k msg/s offered). The server logs `rejecting client request on non-primary
partition replica` for the refused sends:
| topic | primaries | achieved | send p50 | send p99 | server CPU |
| --- | --- | --- | --- | --- | --- |
| 6 partitions, fresh cluster | all on one node | 46k msg/s | - | 21 ms | - |
| 6 partitions, after three single-node restarts | spread over nodes |
11,984 msg/s | 2.6 ms | 4,054 ms | 0.1-0.2 cores |
| 1 partition, same load | one primary | 45,830 msg/s | - | 10 ms | - |
The 4,054 ms p99 matches the two 2 s windows per misrouted send.
## Code references (`master` @ `43fb44364`)
- `core/sdk/src/tcp/tcp_client.rs:83`: `TRANSIENT_FAILOVER_CHECK_INTERVAL =
2s`.
- `core/sdk/src/tcp/tcp_client.rs:1699-1704` (`send_raw_vsr_attempt`):
replays
`TransientNotAccepted` on the same connection until the transient deadline.
- `core/sdk/src/tcp/tcp_client.rs:1436-1445` (`send_raw_retaining_header`):
the
first refusal only takes `routing_lock` and `continue`s, so a second full
window runs on the same node before any routing decision. This is where the
4 s instead of 2 s comes from.
- `core/sdk/src/tcp/tcp_client.rs:1450-1525`: the leader check, then
`RosterWalk` and `settle_on_endpoint` (`:1032`) move the session itself.
- `core/sdk/src/poll_routing.rs`: polls and offset writes get the partition
primary (`GET_POLL_ROUTING`) and use a per-node data connection. Sends
have no
such path.
## Impact
- A producer writing several partitions loses most of its throughput after
ordinary failovers (here 45k -> 12k msg/s), with 4 s tail latency and an
idle
server.
- Partition primaries stay where the failovers left them, so the stalls
continue for as long as the primaries stay split.
- Every bounce is a disconnect, reconnect and sign-in, which adds session
churn
on the server.
## Suggested fix
Route sends like polls: resolve the target partition's primary and send over
a
data connection to that node, keeping the session where it is. Cache the
route
and refresh it on `TransientNotAccepted`. The existing `PollRouter`
connection
pool, session binding and generation fencing look reusable. A send would need
the dedup identity of the connection it is sent on, as replicated offset
writes
already have. A smaller step is to skip the second transient window. A
refusal
proves the request was never admitted, so after taking `routing_lock` the
request could go straight to the routing decision instead of replaying for
another 2 s. That halves the stall but does not stop the bouncing. The Go SDK
would need the same change.
## Contribution
- [ ] I'm willing to submit a pull request to fix this bug
(the failing test is ready as a PR; the fix is open for discussion)
--
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]
