Skip to content

[fix](changelog) Report 5101 for @incr visibility-wait timeouts in shared-nothing mode - #70571

Open
dragonknightk wants to merge 1 commit into
apache:masterfrom
dragonknightk:fix/incr-classic-visible-wait-timeout-5101
Open

dragonknightk wants to merge 1 commit into
apache:masterfrom
dragonknightk:fix/incr-classic-visible-wait-timeout-5101

Conversation

@dragonknightk

Copy link
Copy Markdown

Background

An @incr read first sets a read fence on the master FE and waits until every transaction that can land in the requested window is visible. Bounded, strongly consistent reads in shared-storage mode wait in TSOService.waitForReadableWindow(). Other strongly consistent reads drain earlier transactions on the target tables; in shared-nothing mode they then take each table's read lock to wait for publishers, and a follower FE replays the journal up to the fence. Each wait is bounded by change_visible_timeout_ms.

What problem does this PR solve?

Issue Number: close #70279
Related PR: #67820 (added IncrWindowNotReadyException and 5101 for the shared-storage wait), #67181 (introduced the drain timeout), #67594 (introduced the publisher-lock and follower-replay timeouts)
PR Type: Bugfix

Problem Summary:

In shared-nothing mode, a timeout in the transaction drain, the publisher lock wait or the follower's journal replay reaches the client as a generic error without error code 5101 (ERR_INCR_VISIBLE_WAIT_TIMEOUT). Clients that retry the same window on 5101, such as the Flink Doris Connector, therefore fail the job. This PR throws IncrWindowNotReadyException with 5101 from all three waits and gives a follower's fence RPC 1000 ms of extra socket time, so the master's typed error reaches it first. Most of the diff is tests. After an upgrade, clients that already retry 5101 can retry the same window without client changes.

Details

  • Frequency: When an earlier transaction on a target table, such as a long-running load, stays open longer than change_visible_timeout_ms. It also happens when a publisher holds a target table's write lock that long, or when a follower runs out of time to replay the journal.
  • Root cause: The three waits report their deadline with a plain UserException, which carries ERR_UNKNOWN_ERROR. StmtExecutor, the master fence RPC and DorisFlightSqlProducer keep the error code only for IncrWindowNotReadyException. A follower's fence RPC also used change_visible_timeout_ms as its socket timeout, except for bounded, strongly consistent shared-storage reads, so a master-side timeout could arrive on the follower as a socket error.
  • Why existing tests missed it: The tests that assert 5101 cover only the shared-storage wait. The shared-nothing fence tests cover only the success path.
  • Fix: waitForPreviousTransactions(), synchronizeClassicPublishers() and the follower replay check in waitForVisible() throw IncrWindowNotReadyException with ERR_INCR_VISIBLE_WAIT_TIMEOUT. The reason field keeps the old diagnostics: the transaction ID watermark, the database and table IDs, or the fence's journal ID. Interruption and a failed transaction check still throw a plain UserException. acquireFenceFromMaster() adds 1000 ms to the socket timeout whenever the read waits for transactions.
  • Other paths and branches: Shared-storage reads in which some relation has no explicit end also use the drain. Their drain timeout now reports 5101 too, and their follower fence RPC gets the same 1000 ms.
  • Behavior change: The error message starts with ERR_INCR_VISIBLE_WAIT_TIMEOUT instead of the old timeout ... text. Over Arrow Flight these errors return UNAVAILABLE with doris-error-code metadata instead of INTERNAL. A follower's fence RPC for a strongly consistent read can wait up to 1000 ms longer before its socket times out.

Testing

  • testClassicVisibleWaitTimeoutsReportVisibleWaitTimeout (FE unit test, local): a drain timeout and a publisher-lock timeout in shared-nothing mode report 5101 on the master, in the fence RPC response, and on a non-master FE that decodes that response. It also shows that the non-master FE's socket timeout includes the extra 1000 ms.
  • testClassicFollowerJournalReplayTimeoutReportsVisibleWaitTimeout (FE unit test, local): a follower that runs out of time to replay the journal reports 5101.
  • testEventualConsistentFollowerFenceKeepsSessionSocketTimeout (FE unit test, local): an eventual-consistent read keeps the session timeout as its socket timeout.
  • Each check above fails on the code before this change or under the matching mutation: reverting any of the three throws, removing the 1000 ms, or adding it to every read.
  • TimeBasedChangeVisibleWaiterTest, TSOServiceTest, DorisFlightSqlProducerTest and StmtExecutorTest pass locally with run-fe-ut.sh. Checkstyle 9.3 reports no violations in the changed Java files.
  • changelog_p0/test_changelog_incr_visible_wait_timeout (regression suite, shared-nothing only): a read blocked by a precommitted two-phase-commit load fails with ERR_INCR_VISIBLE_WAIT_TIMEOUT. After the load commits, the same window returns the rows written before the window end. The suite needs a cluster and was not run locally. It compiles with Groovy 4.0.19 and is left to CI.

Notes for Reviewers

  • retryAfterMs is 0 for these timeouts. The shared-storage path uses the TSO window duration, which says nothing about when an earlier transaction will finish.
  • requestedEndTimestampMs is 0 when no relation has an explicit end timestamp.
  • Follow-up, not changed here: after JournalObservable.waitOn() returns, waitForVisible() does not check again that the replayed journal ID reached the fence's maxJournalId.

Release note

In shared-nothing mode, an @incr read that times out waiting for transactions to become visible now fails with error code 5101 (ERR_INCR_VISIBLE_WAIT_TIMEOUT) instead of a generic error.

Check List (For Author)

  • Behavior changed: Yes (see Details)
  • Does this need documentation: No
  • Pre-submission status: Partially verified: FE unit tests pass locally; the new regression suite needs a cluster, was not run locally, and is left to CI

AI Disclosure

  • Tool: Grok Bot, working for dragonknightk
  • Generated: the code change, the unit tests, the regression suite, and this description
  • Human review: All generated code, tests, and this description were reviewed by a human before submission.

…ared-nothing mode

### Background

An `@incr` read first sets a read fence on the master FE and waits until every transaction that can land in the requested window is visible. Bounded, strongly consistent reads in shared-storage mode wait in `TSOService.waitForReadableWindow()`. Other strongly consistent reads drain earlier transactions on the target tables; in shared-nothing mode they then take each table's read lock to wait for publishers, and a follower FE replays the journal up to the fence. Each wait is bounded by `change_visible_timeout_ms`.

### What problem does this PR solve?

Issue Number: close issue 70279
Related PR: PR 67820 (added `IncrWindowNotReadyException` and 5101 for the shared-storage wait), PR 67181 (introduced the drain timeout), PR 67594 (introduced the publisher-lock and follower-replay timeouts)
PR Type: Bugfix

Problem Summary:

In shared-nothing mode, a timeout in the transaction drain, the publisher lock wait or the follower's journal replay reaches the client as a generic error without error code 5101 (`ERR_INCR_VISIBLE_WAIT_TIMEOUT`). Clients that retry the same window on 5101, such as the Flink Doris Connector, therefore fail the job. This PR throws `IncrWindowNotReadyException` with 5101 from all three waits and gives a follower's fence RPC 1000 ms of extra socket time, so the master's typed error reaches it first. Most of the diff is tests. After an upgrade, clients that already retry 5101 can retry the same window without client changes.

### Details

- **Frequency:** When an earlier transaction on a target table, such as a long-running load, stays open longer than `change_visible_timeout_ms`. It also happens when a publisher holds a target table's write lock that long, or when a follower runs out of time to replay the journal.
- **Root cause:** The three waits report their deadline with a plain `UserException`, which carries `ERR_UNKNOWN_ERROR`. `StmtExecutor`, the master fence RPC and `DorisFlightSqlProducer` keep the error code only for `IncrWindowNotReadyException`. A follower's fence RPC also used `change_visible_timeout_ms` as its socket timeout, except for bounded, strongly consistent shared-storage reads, so a master-side timeout could arrive on the follower as a socket error.
- **Why existing tests missed it:** The tests that assert 5101 cover only the shared-storage wait. The shared-nothing fence tests cover only the success path.
- **Fix:** `waitForPreviousTransactions()`, `synchronizeClassicPublishers()` and the follower replay check in `waitForVisible()` throw `IncrWindowNotReadyException` with `ERR_INCR_VISIBLE_WAIT_TIMEOUT`. The reason field keeps the old diagnostics: the transaction ID watermark, the database and table IDs, or the fence's journal ID. Interruption and a failed transaction check still throw a plain `UserException`. `acquireFenceFromMaster()` adds 1000 ms to the socket timeout whenever the read waits for transactions.
- **Other paths and branches:** Shared-storage reads in which some relation has no explicit end also use the drain. Their drain timeout now reports 5101 too, and their follower fence RPC gets the same 1000 ms.
- **Behavior change:** The error message starts with `ERR_INCR_VISIBLE_WAIT_TIMEOUT` instead of the old `timeout ...` text. Over Arrow Flight these errors return `UNAVAILABLE` with `doris-error-code` metadata instead of `INTERNAL`. A follower's fence RPC for a strongly consistent read can wait up to 1000 ms longer before its socket times out.

### Testing

- `testClassicVisibleWaitTimeoutsReportVisibleWaitTimeout` (FE unit test, local): a drain timeout and a publisher-lock timeout in shared-nothing mode report 5101 on the master, in the fence RPC response, and on a non-master FE that decodes that response. It also shows that the non-master FE's socket timeout includes the extra 1000 ms.
- `testClassicFollowerJournalReplayTimeoutReportsVisibleWaitTimeout` (FE unit test, local): a follower that runs out of time to replay the journal reports 5101.
- `testEventualConsistentFollowerFenceKeepsSessionSocketTimeout` (FE unit test, local): an eventual-consistent read keeps the session timeout as its socket timeout.
- Each check above fails on the code before this change or under the matching mutation: reverting any of the three throws, removing the 1000 ms, or adding it to every read.
- `TimeBasedChangeVisibleWaiterTest`, `TSOServiceTest`, `DorisFlightSqlProducerTest` and `StmtExecutorTest` pass locally with `run-fe-ut.sh`. Checkstyle 9.3 reports no violations in the changed Java files.
- `changelog_p0/test_changelog_incr_visible_wait_timeout` (regression suite, shared-nothing only): a read blocked by a precommitted two-phase-commit load fails with `ERR_INCR_VISIBLE_WAIT_TIMEOUT`. After the load commits, the same window returns the rows written before the window end. The suite needs a cluster and was not run locally. It compiles with Groovy 4.0.19 and is left to CI.

### Notes for Reviewers

- `retryAfterMs` is 0 for these timeouts. The shared-storage path uses the TSO window duration, which says nothing about when an earlier transaction will finish.
- `requestedEndTimestampMs` is 0 when no relation has an explicit end timestamp.
- Follow-up, not changed here: after `JournalObservable.waitOn()` returns, `waitForVisible()` does not check again that the replayed journal ID reached the fence's `maxJournalId`.

### Release note

In shared-nothing mode, an `@incr` read that times out waiting for transactions to become visible now fails with error code 5101 (`ERR_INCR_VISIBLE_WAIT_TIMEOUT`) instead of a generic error.

### Check List (For Author)

- Behavior changed: Yes (see Details)
- Does this need documentation: No
- Pre-submission status: Partially verified: FE unit tests pass locally; the new regression suite needs a cluster, was not run locally, and is left to CI

### AI Disclosure

- Tool: Grok Bot, working for dragonknightk
- Generated: the code change, the unit tests, the regression suite, and this description
- Human review: All generated code, tests, and this description were reviewed by a human before submission.

Signed-off-by: dragonknightk <37928252+dragonknightk@users.noreply.github.com>
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.

[Bug] @incr visibility-wait timeout in shared-nothing mode is reported without error code 5101

1 participant