Transaction stuck

[darkdarkdragon]

Version & Environment

Redpanda version: (use rpk version): v22.3.10 (rev 1f78ad9)

Ubuntu 22.04.1 LTS
franz-go v1.9.0

What went wrong?

Producer can't start, gives error

unable to commit transaction offsets: UNKNOWN_SERVER_ERROR: The server experienced an unexpected error when processing the request.

What should have happened instead?

Producer should have been started.

How to reproduce the issue?

Additional information

Server logs:

Jan 14 05:06:13 kafka-prod-2 rpk[1727]: WARN  2023-01-14 05:06:13,174 [shard 13] tx - [N:nomad_topic S:Stable G:516] group.cc:1808 - can't begin a tx {producer_identity: id=2242, epoch=258} with tx_seq 21969: a producer id is already involved in a tx with tx_seq 21222
Jan 14 05:06:13 kafka-prod-2 rpk[1727]: WARN  2023-01-14 05:06:13,174 [shard 15] tx - tx_gateway_frontend.cc:1451 - error on begining group tx: tx_errc::unknown_server_error

[bharathv]

Is this a transient issue or does it persist for long period? Helps if you have a simple repro.

A quick scan of the code suggests this may be possible if the consumer offsets topic is rebalancing / changing leadership etc in which case we could throw a retryable error, but we need to validate if that is the case. Helps to have lower log levels or a simpler repro. I think we may have an issue open for this.. @rystsov may know?

[rystsov]

@bharathv it looks like the consumer groups elected new leader and it either started processing new request before it had replayed the log or there is something with replaying the log which doesn't update some state, looking...

[rystsov]

Ivan, we're going to dig to the bottom of this and cover this edge case.

However even when we fix it there is always a slight chance of running into the fatal errors with the indecisive outcome (unknown server error, invalid txn state or timeout). The application using Kafka client should anticipate it and be ready to recreate a producer when it happens. Upon init_producer_id or when the last tx expires (see transaction.timeout.ms) Redpanda either rolls forward or backward the last tx (depending on its state) and recovers the system to the consistent state.

It's easy to illustrate the need of handling the fatal errors with the timeouts: because network isn't 100% reliable a commit request may time and it may happen on the request path as well as on the response path so the outcome of the operation is unknown. Unknown server error (USE) sounds scary but RP returns it when it runs into a rare non critical unexpected situation. And it isn't specific to Redpanda, Kafka too may return USE for any API request: it intersects all exceptions and when it isn't mapped to any Kafka error they return USE.

[bharathv]

@rystsov It could be this too, no? A temporary blip, seems we translate it to USE. or am I missing something?

else if (in_state(group_state::completing_rebalance)) {
        cluster::begin_group_tx_reply reply;
        reply.ec = cluster::tx_errc::rebalance_in_progress; <==
        co_return reply;
    }

[rystsov]

@bharathv It's a problem (good catch, we should retry begin_group_tx on that error just like we retry begin_tx) but most likely isn't this problem; we have this reported log line

Jan 14 05:06:13 kafka-prod-2 rpk[1727]: WARN  2023-01-14 05:06:13,174 [shard 13] tx - [N:nomad_topic S:Stable G:516] group.cc:1808 - can't begin a tx {producer_identity: id=2242, epoch=258} with tx_seq 21969: a producer id is already involved in a tx with tx_seq 21222

and it definitely causes USE

[rystsov]

failed ci run: https://buildkite.com/redpanda/vtools/builds/5398#0185dd71-ef3d-45f6-aa32-350e714ec148

[bharathv]

@rystsov this is technically not a ci-failure right? I'm removing it, but feel free to add it back if I'm wrong.

[piyushredpanda]

@bharathv : More a tracking thing than anything. Treat it as a test failure -- chaos or CI is kinda moot.

[mmaslankaprv]

@rystsov should we mark this issue with sev/high ?

[rystsov]

/backport v22.3.x