pingcap / pingcap/tidb

DDL can succeed with an earlier DML that makes commitTs-ordered CDC replay fail

Open
#69,514 1 comment 0 reactions 1 assignee Claimed by @D3Hunter View on GitHub
component/ddl may-affects-7.5 may-affects-8.1 may-affects-8.5 severity/major type/bug
Dominant language
Go
Stars
40.5k
Forks
6.2k
PR merge metrics
PR metrics pending

Description

## Bug Report

In a TiCDC weekly random DDL test, upstream TiDB accepted a DDL even though TiCDC later observed an earlier DML commit on the same table that makes the DDL impossible to replay in commitTs order.

TiCDC must replicate DML and DDL by commitTs order. In this case, CDC sees a row with `bin=NULL` committed before `ALTER TABLE ... MODIFY COLUMN bin INT NOT NULL`. When CDC replays that history downstream, the downstream TiDB correctly rejects the DDL with `Data truncated for column 'bin' at row 1`. The same DDL had already succeeded on upstream, so the upstream history is not replayable by commitTs.

## Affected table and statements

Table: `db4.t13_r_4009145`

Table ID in the failed run: `5570`

DDL:

```sql
ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL;
```

Critical timestamps observed by CDC:

- DML commitTs: `467328738632925230`, row has `bin=NULL`
- DDL startTs: `467328738632925238`
- DDL commitTs: `467328738632925261`

So the order seen by CDC is:

```text
DML commitTs 467328738632925230 < DDL startTs 467328738632925238 < DDL commitTs 467328738632925261
```

## Environment

This was observed in a TiCDC integration test run on 2026-06-29.

TiDB binary used by the test:

```text
Release Version: v9.0.0-beta.2.pre-1920-ga239f120bb
Edition: Community
Git Commit Hash: a239f120bbb14b4d095f0c1bcb4cc81c0d376afb
Git Branch: HEAD
UTC Build Time: 2026-06-26 05:32:50
GoVersion: go1.25.10
Store: unistore
```

Other components:

```text
TiKV Release Version: 9.0.0-beta.2
TiKV Git Commit Hash: 56a397a1766e5da57670796b31013d0c720c196b
PD Release Version: v9.0.0-beta.2.pre-419-g6a29eb9
PD Git Commit Hash: 6a29eb9fe9a9abef457b2c8387085f66750e777a
```

TiCDC test branch/commit:

```text
branch: codex/weekly-rand-ddl-debug-20260628
commit: 66abece82 eventservice: advance scan window for pending syncpoints
case: weekly_rand_single
```

## Actual logs

The runner/DDL trace shows that the upstream test side considered the target DDL successful. The runner trace uses UTC while TiDB/CDC logs use `+08:00`.

```text
2026/06/29 07:20:55.269879 kind=drop_and_recreate_table target=`db4`.`t13_r_4009145` status=ok sql="DROP TABLE IF EXISTS `db4`.`t13_r_4009145`; CREATE TABLE IF NOT EXISTS `db4`.`t13_r_4009145` (... `bin` VARBINARY(64), PRIMARY KEY (`id`))" err=""
2026/06/29 07:20:59.580850 kind=truncate_table target=`db4`.`t13_r_4009145` status=ok sql="TRUNCATE TABLE `db4`.`t13_r_4009145`" err=""
2026/06/29 07:21:01.460252 kind=modify_column_type target=`db4`.`t13_r_4009145` status=ok sql="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL" err=""
```

Upstream TiDB also logged the target DDL job as submitted and then the crucial operation was recorded without a corresponding failure for this target DDL:

```text
[2026/06/29 15:21:01.300 +08:00] [INFO] [executor.go:7260] ["DDL job submitted"] [category=ddl] [job="ID:5587, Type:modify column, State:queueing, SchemaState:none, SchemaID:122, TableID:5570, RowCount:0, ArgLen:1, start time: 2026-06-29 15:21:01.26 +0800 CST, Err:, ErrCount:0, SnapshotVersion:0, Version: v2, analyze_state:0, stage:0, UniqueWarnings:0"] [query="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL"]
[2026/06/29 15:21:01.305 +08:00] [INFO] [modify_column.go:275] ["get type for modify column"] [category=ddl] [query="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL"] [oldColumnName=bin] [oldColumnID=7] [type="reorg row and index"]
[2026/06/29 15:21:01.460 +08:00] [INFO] [session.go:5104] ["CRUCIAL OPERATION"] [conn=2109736096] [schemaVersion=15228] [cur_db=] [sql="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL"] [user=root@%]
```

CDC then observed the event order for table ID `5570`. The DML at `467328738632925230` was sent before the DDL at `467328738632925261`:

```text
[2026/06/29 15:22:15.232 +08:00] [DEBUG] [event_broker.go:228] ["send dml event to dispatcher"] [changefeedID=default/weeklyrand] [dispatcherID=880993828116153247512304315796146419391] [tableID=5570] [seq=8] [lastCommitTs=467328738632925230] [lastStartTs=467328738632925229]
[2026/06/29 15:22:15.239 +08:00] [INFO] [event_broker.go:254] ["send ddl event to dispatcher"] [changefeedID=default/weeklyrand] [dispatcherID=880993828116153247512304315796146419391] [DDLSpanTableID=5570] [EventTableID=5570] [query="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL"] [commitTs=467328738632925261] [seq=9] [mode=0]
```

The DML payload for `seq=8` contains `bin=NULL`:

```text
[2026/06/29 15:22:15.620 +08:00] [DEBUG] [basic_dispatcher.go:606] ["dispatcher receive all event"] [dispatcher=880993828116153247512304315796146419391] [mode=0] [eventType=DMLEvent] [event="DMLEvent{Version: 1, DispatcherID: 880993828116153247512304315796146419391, Seq: 8, PhysicalTableID: 5570, StartTs: 467328738632925229, CommitTs: 467328738632925230, Table: db4.t13_r_4009145, Checksum: [], Length: 1, Size: 194, Rows: Insert: Row: 1829, 369095, FItUvkKcYnv2VLBe0lBJDt3nSA4eU6ll, 98.56, 2023-11-14 22:43:49, {\"id\": 1829, \"tbl\": \"t13_r_4009145\"}, NULL;}"]
[2026/06/29 15:22:15.630 +08:00] [DEBUG] [sql_builder.go:101] ["Total SQL Count: 1, Row Count: 1, Writer ID: 25 :[001] Query: REPLACE INTO `db4`.`t13_r_4009145` (`id`,`a`,`b`,`c`,`d`,`e`,`bin`) VALUES (?,?,?,?,?,?,?), Args: (1829, 369095, FItUvkKcYnv2VLBe0lBJDt3nSA4eU6ll, 98.56, 2023-11-14 22:43:49, {\"id\": 1829, \"tbl\": \"t13_r_4009145\"}, NULL),CommitTs: [467328738632925230],StartTs: [467328738632925229],End"]
```

The DDL event seen by CDC has `StartTs=467328738632925238` and `FinishedTs=467328738632925261`:

```text
[2026/06/29 15:22:15.645 +08:00] [DEBUG] [basic_dispatcher.go:606] ["dispatcher receive all event"] [dispatcher=880993828116153247512304315796146419391] [mode=0] [eventType=DDLEvent] [event="DDLEvent{Version: 1, DispatcherID: 880993828116153247512304315796146419391, Type: 12, SchemaID: 122, SchemaName: db4, TableName: t13_r_4009145, Query: ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL, TableInfo: TableInfo{schema:db4, table:t13_r_4009145, tableID:5570, ... updateTS:467328738632925238}, StartTs: 467328738632925238, FinishedTs: 467328738632925261, Seq: 9, ...}"]
[2026/06/29 15:22:15.651 +08:00] [INFO] [basic_dispatcher.go:698] ["dispatcher receive ddl event"] [dispatcher=880993828116153247512304315796146419391] [query="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL"] [table=5570] [commitTs=467328738632925261] [seq=9]
```

When CDC replayed these events downstream in commitTs order, downstream TiDB rejected the same DDL:

```text
[2026/06/29 15:22:15.706 +08:00] [WARN] [session.go:2726] ["run statement failed"] [conn=893386926] [schemaVersion=14695] [error="[ddl:1265]Data truncated for column 'bin' at row 1"]
[2026/06/29 15:22:15.706 +08:00] [INFO] [session.go:5104] ["CRUCIAL OPERATION"] [conn=893386926] [schemaVersion=14695] [cur_db=db4] [sql="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL"] [user=root@%]
[2026/06/29 15:22:15.707 +08:00] [WARN] [conn.go:1326] ["command dispatched failed"] [sql="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL"] [err="[ddl:1265]Data truncated for column 'bin' at row 1\ngithub.com/pingcap/tidb/pkg/ddl.checkForNullValue\n\t/workspace/source/tidb/pkg/ddl/column.go:1122\ngithub.com/pingcap/tidb/pkg/ddl.GetModifiableColumnJob\n\t/workspace/source/tidb/pkg/ddl/modify_column.go:1970\ngithub.com/pingcap/tidb/pkg/ddl.(*executor).ModifyColumn\n\t/workspace/source/tidb/pkg/ddl/executor.go:3545"]
```

CDC kept retrying the DDL and eventually the changefeed entered warning:

```text
[2026/06/29 15:23:18.127 +08:00] [WARN] [mysql_writer_ddl.go:237] ["Execute DDL with error, retry later"] [startTs=467328738632925238] [commitTs=467328738632925261] [ddl="ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL"] [error="Error 1265 (01000): Data truncated for column 'bin' at row 1"]
[2026/06/29 15:23:18.128 +08:00] [ERROR] [dispatcher_manager.go:693] ["Event Dispatcher Manager Meets Error"] [changefeedID=default/weeklyrand] [error="[CDC:ErrReachMaxTry]reach maximum try: 20, error: [CDC:ErrExecDDLFailed]exec DDL failed ... ALTER TABLE `db4`.`t13_r_4009145` MODIFY COLUMN `bin` INT NOT NULL ... Error 1265 (01000): Data truncated for column 'bin' at row 1"]
[2026/06/29 15:23:18.269 +08:00] [INFO] [controller.go:687] ["changefeed status changed"] [changefeed=default/weeklyrand] [state=warning]
```

## Why CDC cannot handle this correctly

CDC's downstream replay model is commitTs ordered. For this table, CDC only has a linear history where the `bin=NULL` DML commits before the `MODIFY COLUMN bin INT NOT NULL` DDL.

If CDC replays by commitTs, downstream TiDB rejects the DDL because the preceding row contains `bin=NULL`. If CDC reorders or skips the DML to make the DDL pass, it would violate the upstream commitTs order and could corrupt downstream history. Therefore CDC cannot make this sequence converge unless upstream TiDB produces a commitTs history that is replayable.

## Expected behavior

TiDB should not produce a history where:

1. A DML that writes `bin=NULL` has commitTs smaller than the DDL startTs/commitTs.
2. A later `ALTER TABLE ... MODIFY COLUMN bin INT NOT NULL` succeeds upstream.
3. The same history fails when replayed in commitTs order on another TiDB.

Either the upstream DDL should fail consistently, or the commitTs/visibility/order should ensure a downstream system replaying by commitTs can reproduce the upstream result.

## Actual behavior

Upstream TiDB accepted the DDL, but the commitTs-ordered CDC history contains an earlier DML with `bin=NULL`. Downstream TiDB rejects the DDL, so TiCDC cannot replicate this table correctly and the changefeed enters warning.

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.