Recover Table cause drainer exit in TiDB 3.0.0

[ruiaylin]

The drainer exit When we do table recover command on TiDB cluster, I think this is a bug.

TiDB sql command

drop table sbtest4; 
recover table sysbench.sbtest4 ; 
// check the ddl jobs

mysql> admin show ddl jobs
    -> ;
+--------+----------+------------+---------------+--------------+-----------+----------+-----------+-----------------------------------+--------+
| JOB_ID | DB_NAME  | TABLE_NAME | JOB_TYPE      | SCHEMA_STATE | SCHEMA_ID | TABLE_ID | ROW_COUNT | START_TIME                        | STATE  |
+--------+----------+------------+---------------+--------------+-----------+----------+-----------+-----------------------------------+--------+
|     64 | sysbench | sbtest5    | create table  | public       |        41 |       63 |         0 | 2019-07-09 19:07:38.022 +0800 CST | synced |
|     62 | db24     |            | create schema | public       |        61 |        0 |         0 | 2019-07-09 15:19:22.836 +0800 CST | synced |
|     60 | sysbench |            | drop table    | none         |        41 |       43 |         0 | 2019-07-09 13:20:28.702 +0800 CST | synced |
|     59 |          |            | drop schema   | none         |        57 |        0 |         0 | 2019-07-09 13:11:52.302 +0800 CST | synced |
|     58 |          |            | create schema | public       |        57 |        0 |         0 | 2019-07-09 10:08:47.516 +0800 CST | synced |
|     56 | sysbench | sbtest4    | recover table | public       |        41 |       49 |         0 | 2019-07-09 09:57:17.215 +0800 CST | synced |
|     55 | sysbench | sbtest4    | drop table    | none         |        41 |       49 |         0 | 2019-07-09 09:56:54.265 +0800 CST | synced |
|     54 | sysbench | sbtest3    | add index     | public       |        41 |       52 |     10000 | 2019-07-09 09:47:21.565 +0800 CST | synced |
|     53 | sysbench | sbtest3    | create table  | public       |        41 |       52 |         0 | 2019-07-09 09:47:19.815 +0800 CST | synced |
|     51 | sysbench | sbtest4    | add index     | public       |        41 |       49 |     10000 | 2019-07-09 09:47:18.565 +0800 CST | synced |
+--------+----------+------------+---------------+--------------+-----------+----------+-----------+-----------------------------------+--------+

Drainer Error

[2019/07/09 13:20:30.290 +08:00] [INFO] [collector.go:280] ["get ddl job"] [job="ID:60, Type:drop table, State:synced, SchemaState:none, SchemaID:41, TableID:43, RowCount:0, ArgLen:0, start time: 2019-07-09 13:20:28.702 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0"]
[2019/07/09 13:20:30.291 +08:00] [ERROR] [server.go:267] ["syncer exited abnormal"] [
    error="handle ddl job ID:56, Type:none, State:synced, SchemaState:public, SchemaID:41, TableID:49, RowCount:0, ArgLen:0, start time: 2019-07-09 09:57:17.215 +0800 CST, Err:[meta:1146]table doesn't exist, ErrCount:1, SnapshotVersion:0 failed, the schema info: {\n\t\thasImplicitCol: false,\n\t\tschemaMetaVersion: 0,\n\t\tschemaNameToID: {\n\t\t\tmysql: 3,\n\t\t\tsysbench: 41,\n\t\t\ttest: 1\n\t\t},\n\t\ttableIDToName: {\n\t\t\t11: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: columns_priv\n\t\t\t},\n\t\t\t13: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: GLOBAL_VARIABLES\n\t\t\t},\n\t\t\t15: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: tidb\n\t\t\t},\n\t\t\t17: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: help_topic\n\t\t\t},\n\t\t\t19: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: stats_meta\n\t\t\t},\n\t\t\t21: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: stats_histograms\n\t\t\t},\n\t\t\t23: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: stats_buckets\n\t\t\t},\n\t\t\t25: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: gc_delete_range\n\t\t\t},\n\t\t\t27: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: gc_delete_range_done\n\t\t\t},\n\t\t\t29: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: stats_feedback\n\t\t\t},\n\t\t\t31: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: role_edges\n\t\t\t},\n\t\t\t33: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: default_roles\n\t\t\t},\n\t\t\t35: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: bind_info\n\t\t\t},\n\t\t\t37: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: stats_top_n\n\t\t\t},\n\t\t\t39: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: expr_pushdown_blacklist\n\t\t\t},\n\t\t\t43: {\n\t\t\t\tdb-name: sysbench,\n\t\t\t\ttbl-name: sbtest1\n\t\t\t},\n\t\t\t44: {\n\t\t\t\tdb-name: sysbench,\n\t\t\t\ttbl-name: sbtest2\n\t\t\t},\n\t\t\t5: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: user\n\t\t\t},\n\t\t\t52: {\n\t\t\t\tdb-name: sysbench,\n\t\t\t\ttbl-name: sbtest3\n\t\t\t},\n\t\t\t7: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: db\n\t\t\t},\n\t\t\t9: {\n\t\t\t\tdb-name: mysql,\n\t\t\t\ttbl-name: tables_priv\n\t\t\t}\n\t\t}\n\t}: table sbtest4(49) not found"] [errorVerbose="table sbtest4(49) not found\n
github.com/pingcap/errors.NotFound

This mean that handing the ddl job ( recover table ) issue the error info.

I check the source code of drainer , add the skip logic for the ActionRecoverTable ddl job. build a new drainer version for test, it worked .

// schema.go line 393
// 25 means: job type is ActionRecoverTable
        if (job.Type==25){
             log.Info("ActionRecoverTable Occur Skip ~~~~~ ", zap.Int64("Job id:", job.ID), zap.Uint8(" type:", uint8(job.Type)), zap.Int64(" SchemaID:", job.SchemaID), zap.Int64(" TableID:",job.TableID))
            return
        }

[IANTHEREAL]

Sorry for it, it is a compatibility bug, and not easy to fix now!

• TiDB Binlog don’t support recover table
• other downstream systems , like MySQL, don’t have same semantics with recover table.

So recover table command is not recommended in this case now 😢

But we would give a workaround way ASAP @ruiaylin

[ruiaylin]

@GregoryIan Got it , Thanks

[suzaku]

674 handles this issue by treating recover like create table, so that recovers executed before Drainer starts would not break newer DMLs of the recovered table.