pingcap / pingcap/tidb

[BR] Filtered PiTR makes AUTO_ID_CACHE=1 tables writable before autoid rebase, causing transient duplicate-key errors

Open
#70,654 2 comments 0 reactions 0 assignees View on GitHub
affects-8.5 component/br may-affects-25.10 may-affects-26.3 may-affects-7.5 may-affects-8.1 severity/major type/bug
Dominant language
Go
Stars
40.5k
Forks
6.2k
PR merge metrics
PR metrics pending

Description

## Bug Report

PR #70253 (the release-8.5 backport of #69573) fixes #69485 by rebasing the centralized auto-increment allocator after PiTR log replay for tables using `AUTO_ID_CACHE=1`.

However, in the filtered PiTR path, BR changes a restored table to `TableModeNormal` before rebasing its auto-increment allocator. During this interval, concurrent implicit-ID inserts can enter normal DML execution with a stale allocator, receive IDs that already exist in the restored data, and fail with `ERROR 1062`.

### 1. Minimal reproduce step (Required)

#### Environment

- TiDB and BR: `v8.5.8-pre`
- TiDB/BR Git commit: `679bbc290e7f52b1865f5a5a4a46c0a40c365526`
- Includes #70253 merge commit: `73f294359d86422f08b4ffc6301be2e03e1b8c17`
- One TiDB, one PD, and one TiKV
- No mixed-version deployment is required

The source and target playground clusters are started sequentially because they can access the same local backup directory.

#### A. Create the PiTR backup on the source cluster

Start the source cluster:

```bash
tiup playground v8.5.8-pre \
--db 1 --pd 1 --kv 1 --tiflash 0 --without-monitor
```

In another terminal:

```bash
export BR_VERSION=v8.5.8-pre
export PD_ADDR=127.0.0.1:2379
export MYSQL_PORT=4000
export LOG_TASK=h-filtered-race
export CASE_ROOT="$(mktemp -d /tmp/h-filtered-race.XXXXXX)"

mysql -h127.0.0.1 -P"$MYSQL_PORT" -uroot <<'SQL'
CREATE DATABASE autoid_pitr2;
CREATE TABLE autoid_pitr2.t (
id BIGINT PRIMARY KEY AUTO_INCREMENT,
data BIGINT NOT NULL
) AUTO_ID_CACHE=1;
INSERT INTO autoid_pitr2.t(data) VALUES (0);
SQL

tiup br:"$BR_VERSION" log start \
--pd "$PD_ADDR" \
--task-name "$LOG_TASK" \
--storage "local://$CASE_ROOT/log"

tiup br:"$BR_VERSION" backup full \
--pd "$PD_ADDR" \
--storage "local://$CASE_ROOT/full"
```

Insert another 5,000 rows after the full backup:

```bash
mysql -h127.0.0.1 -P"$MYSQL_PORT" -uroot <<'SQL'
SET @@cte_max_recursion_depth = 6000;
INSERT INTO autoid_pitr2.t(data)
WITH RECURSIVE seq AS (
SELECT 1 AS n
UNION ALL
SELECT n + 1 FROM seq WHERE n < 5000
)
SELECT n FROM seq;
SELECT COUNT(*), MIN(id), MAX(id) FROM autoid_pitr2.t;
SQL

export RESTORE_TS="$(
mysql -h127.0.0.1 -P"$MYSQL_PORT" -uroot -Nse \
'SELECT @@tidb_current_ts'
)"

echo "RESTORE_TS=$RESTORE_TS"
date '+restore wall time: %Y-%m-%d %H:%M:%S %z'
```

The source table now contains 5,001 rows with IDs from 1 through 5,001. Poll the following command until `checkpoint[global]` is later than the recorded restore time, then stop log backup:

```bash
tiup br:"$BR_VERSION" log status \
--pd "$PD_ADDR" --task-name "$LOG_TASK"

tiup br:"$BR_VERSION" log stop \
--pd "$PD_ADDR" --task-name "$LOG_TASK"
```

Stop the source playground with Ctrl+C.

#### B. Restore into a clean target while a writer is running

Start another clean target playground:

```bash
tiup playground v8.5.8-pre \
--db 1 --pd 1 --kv 1 --tiflash 0 --without-monitor
```

Before starting BR, run a continuous implicit-ID writer. `--force` keeps the MySQL client running after table-not-found, restore-mode, and duplicate-key errors:

```bash
export WRITER_LOG="$CASE_ROOT/writer.log"

(
i=1
while true; do
printf 'INSERT INTO autoid_pitr2.t(data) VALUES (%d);\n' \
"$((900000 + i))"
i=$((i + 1))
sleep 0.003
done
) | mysql --force -h127.0.0.1 -P"$MYSQL_PORT" -uroot \
>"$WRITER_LOG" 2>&1 &

export WRITER_PID=$!
```

Run filtered PiTR:

```bash
tiup br:"$BR_VERSION" restore point \
--pd "$PD_ADDR" \
--storage "local://$CASE_ROOT/log" \
--full-backup-storage "local://$CASE_ROOT/full" \
--restored-ts "$RESTORE_TS" \
--filter 'autoid_pitr2.*' \
2>&1 | tee "$CASE_ROOT/restore.log"

kill "$WRITER_PID" 2>/dev/null || true
wait "$WRITER_PID" 2>/dev/null || true

grep -E 'ERROR 1062|Duplicate entry' "$WRITER_LOG" | head -20
```

Check the restored table and the next generated ID:

```sql
SELECT COUNT(*) AS row_count,
MAX(id) AS max_id,
SUM(data >= 900000) AS writer_rows
FROM autoid_pitr2.t;

INSERT INTO autoid_pitr2.t(data) VALUES (-1);
SELECT LAST_INSERT_ID() AS marker_id;
```

This is a timing-sensitive race. It reproduced twice without a failpoint in the local environment above. On a fast machine, it might be necessary to repeat the restore against another clean target cluster.

### 2. What did you expect to see? (Required)

During filtered PiTR, restored tables should remain protected from user reads and writes until BR has completed both data replay and auto-increment allocator synchronization.

Writer attempts before restore completion may receive table-not-found or restore-mode errors such as `ERROR 8258`, but they must not enter normal DML execution with a stale allocator.

Once the table becomes writable:

- implicit-ID inserts must not receive IDs that already exist in restored data;
- no duplicate-key error should be caused by the restored auto-ID range;
- generated IDs should be above the restored/persisted high watermark;
- the allocator should remain monotonic.

This matches the documented filtered-PiTR behavior that tables created by PiTR are not readable or writable until the restore task completes:

https://docs.pingcap.com/tidb/v8.5/br-pitr-manual

### 3. What did you see instead (Required)

A pure `v8.5.8-pre` local run reproduced the following sequence:

```text
19:04:50.786 Last writer error while protected:
ERROR 8258: Table t is in mode Restore

19:04:50.800 BR log:
altering table mode

19:04:50.830 Writer started receiving:
ERROR 1062: Duplicate entry '4001' for key 't.PRIMARY'

Duplicate IDs observed: 4001, 4002, ..., 4012

19:04:51.264 Last duplicate-key error: Duplicate entry '4012'

19:04:51.307 Autoid/BR logs:
forceRebase from=8000 to=8000
persistedBase=8000

19:04:51.332 TiDB allocated the corrected range: 8000..12000

19:04:51.361 BR completed: total-kv-count=5001
```

The writer stopped receiving restore-mode errors after the table was changed to normal, but before allocator rebasing completed. During this approximately 0.5-second interval, the stale allocator started at 4,001, overlapping rows already restored through ID 5,001.

After the rebase, the first successful writer row received ID 8,001.

```text
COUNT(*) = 5002
MAX(id) = 8001
writer row = (id=8001, data=900398)
next marker ID = 8002
```

A second clean local run observed duplicates from 4,001 through 4,014, followed by a successful allocation of ID 8,001.

An additional end-to-end validation observed 15 duplicate-key errors for IDs 4,001 through 4,015:

http://ec2-50-16-199-20.compute-1.amazonaws.com/dashboard/validations/04a0ae1a-aed6-4d73-807a-26a555502886

That validation used a v8.5.7 SQL writer and v8.5.8-pre BR, but mixed versions are not a prerequisite because the same failure reproduced on a pure v8.5.8-pre playground.

After BR completed, the table remained usable and the allocator advanced normally. No successfully committed duplicate primary key, silent data corruption, or persistent post-restore failure was observed.

### 4. What is your TiDB version? (Required)

```text
TiDB release: v8.5.8-pre
TiDB Git commit: 679bbc290e7f52b1865f5a5a4a46c0a40c365526
BR release: v8.5.8-pre
Included PR commit: 73f294359d86422f08b4ffc6301be2e03e1b8c17
Topology: 1 TiDB + 1 PD + 1 TiKV
Mixed versions: No
```

## Suspected root cause

For explicitly filtered PiTR, the operations currently happen in this order:

1. restore log KV files;
2. call `SetTableModeToNormal`, making the table writable;
3. wait for schema reload;
4. call `RebaseAutoIncrementIDForSepAutoIncTables`.

Relevant code:

- Restore completion ordering: https://github.com/pingcap/tidb/blob/679bbc290e7f52b1865f5a5a4a46c0a40c365526/br/pkg/task/stream.go#L1767-L1806
- Changing tables to normal mode: https://github.com/pingcap/tidb/blob/679bbc290e7f52b1865f5a5a4a46c0a40c365526/br/pkg/restore/log_client/client.go#L1421-L1474
- Reading the persisted counter and calling `ForceRebase`: https://github.com/pingcap/tidb/blob/679bbc290e7f52b1865f5a5a4a46c0a40c365526/br/pkg/restore/log_client/client.go#L1512-L1553

The table therefore becomes writable while the centralized allocator can still contain its snapshot-era value.

The regression test added by #70253 inserts only after the restore command returns and does not cover a concurrent writer in this explicit-filter window:

https://github.com/pingcap/tidb/blob/679bbc290e7f52b1865f5a5a4a46c0a40c365526/br/tests/br_pitr_autoid_cache/run.sh#L65-L91

## Impact

Trigger conditions:

- filtered PiTR using `restore point --filter`;
- an `AUTO_INCREMENT` table with `AUTO_ID_CACHE=1`;
- log replay advances the persisted counter beyond the snapshot-era allocator state;
- application writes are attempted before BR exits.

User-visible impact:

- transient `ERROR 1062` write failures;
- business operations can be lost when applications do not retry failed inserts;
- high write QPS, a longer schema-reload delay, or many restored tables increases exposure.

If application writers remain quiesced until BR exits, this race is not triggered.

## Expected fix invariant

The restored table should remain under an effective write barrier until schema reload and autoid synchronization have both completed successfully. If schema reload depends on normal mode, an equivalent write-exclusion mechanism should cover the complete interval.

## Evidence boundary

This reproduction confirms that the table becomes normal before autoid rebase and that concurrent inserts can receive restored IDs and fail with `ERROR 1062`. It does not confirm an allocator value advancing from X to Y and then being reset backward to X by `ForceRebase`, successful insertion of duplicate primary keys, or silent/persistent data corruption.

The observed rebase log was:

```text
forceRebase from=8000 to=8000
```

Therefore, allocator rollback should be treated as a separate code-level risk, not as an observed result of this testcase.

## Version relationship

- v8.5.7 does not contain #70253 and remains affected by the original post-PiTR stale-autoid problem in #69485.
- v8.5.8-pre contains #70253 and eventually corrects the allocator, but still exposes the concurrent-write window described here.

This is a remaining ordering hole in the #70253 fix rather than a mixed-version-specific problem.

Contributor guide

Open the contributing guide

Research direction

Start with the restore completion ordering in br/pkg/task/stream.go, then read SetTableModeToNormal and RebaseAutoIncrementIDForSepAutoIncTables in br/pkg/restore/log_client/client.go. Run br/tests/br_pitr_autoid_cache/run.sh and extend coverage for a concurrent writer during filtered PiTR. Done means writers remain protected until allocator synchronization completes, with no transient duplicate-key errors.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
databases, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
48/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.