DDL - mysql-myslq job - increment stsge - Inserting data into the parent table of the foreign key causes the source dtle to panic

[asiroliu]

Description

DDL - mysql-myslq job - increment stsge - Inserting data into the parent table of the foreign key causes the source dtle to panic

Steps to reproduce the issue

1. create mysql-mysql job
2. src mysql exectue sql

mysql> CREATE TABLE parent_2 (id INT NOT NULL, PRIMARY KEY (id));
mysql> CREATE TABLE child_2 (id INT, parent_id INT, CONSTRAINT fk_child_2_1 FOREIGN KEY (parent_id) REFERENCES parent_2(`id`) ON DELETE CASCADE ON UPDATE CASCADE);
mysql> INSERT INTO parent_2 VALUES (1), (2), (3), (4), (5);

3. dest mysql has no data
4. check src dtle log

2022-03-25T17:22:05.811+0800 [DEBUG] client.driver_mgr.dtle: publish.after: driver=dtle @module=dtle.extractor gno=176 job=ddl_create_table_constraint-migration n=1 timestamp=2022-03-25T17:22:05.811+0800
2022-03-25T17:22:05.812+0800 [DEBUG] client.driver_mgr.dtle: ParseQueryEventFlags: driver=dtle bytes=0000000000012000a055000000000603737464042d002d0008000cfe job=ddl_create_table_constraint-migration @module=reader.ParseQueryEventFlags timestamp=2022-03-25T17:22:05.812+0800
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: panic: runtime error: index out of range [28] with length 28: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: : driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: goroutine 547 [running]:: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: github.com/actiontech/dtle/drivers/mysql/common.ParseQueryEventFlags(0xc0016cc1a1, 0x1c, 0x3f, 0x7f0ecc2a0040, 0xc00084ae80, 0x0, 0x3091d78, 0x7, 0x30b5544, 0x12, ...): driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle:    /universe/src/github.com/actiontech/dtle/drivers/mysql/common/binlog.go:283 +0x1015: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: github.com/actiontech/dtle/drivers/mysql/mysql/binlog.(*BinlogReader).handleQueryEvent(0xc000c5db00, 0xc000acf200, 0xc00335ecc0, 0xc0015c1a60, 0xc00168f9a0): driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle:    /universe/src/github.com/actiontech/dtle/drivers/mysql/mysql/binlog/binlog_reader.go:481 +0x11a: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: github.com/actiontech/dtle/drivers/mysql/mysql/binlog.(*BinlogReader).handleEvent(0xc000c5db00, 0xc000acf200, 0xc00335ecc0, 0x0, 0x0): driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle:    /universe/src/github.com/actiontech/dtle/drivers/mysql/mysql/binlog/binlog_reader.go:444 +0x54d: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: github.com/actiontech/dtle/drivers/mysql/mysql/binlog.(*BinlogReader).DataStreamEvents(0xc000c5db00, 0xc00335ecc0, 0xc0010a61c0, 0xc000000003): driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle:    /universe/src/github.com/actiontech/dtle/drivers/mysql/mysql/binlog/binlog_reader.go:950 +0x68a: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: github.com/actiontech/dtle/drivers/mysql/mysql.(*Extractor).StreamEvents(0xc0010a61c0, 0x30b5e11, 0x13): driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle:    /universe/src/github.com/actiontech/dtle/drivers/mysql/mysql/extractor.go:1065 +0x88: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: github.com/actiontech/dtle/drivers/mysql/mysql.(*Extractor).initiateStreaming.func1(0xc0010a61c0): driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle:    /universe/src/github.com/actiontech/dtle/drivers/mysql/mysql/extractor.go:684 +0x90: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle: created by github.com/actiontech/dtle/drivers/mysql/mysql.(*Extractor).initiateStreaming: driver=dtle
2022-03-25T17:22:05.814+0800 [DEBUG] client.driver_mgr.dtle:    /universe/src/github.com/actiontech/dtle/drivers/mysql/mysql/extractor.go:681 +0x67: driver=dtle
2022-03-25T17:22:05.824+0800 [DEBUG] client.driver_mgr.stdio: received EOF, stopping recv loop: driver=dtle err="rpc error: code = Unavailable desc = transport is closing"
2022-03-25T17:22:05.824+0800 [DEBUG] client.driver_mgr: plugin process exited: driver=dtle path=/opt/dtle/usr/share/dtle/nomad-plugin/dtle pid=332 error="exit status 2"
2022-03-25T17:22:05.824+0800 [DEBUG] client.alloc_runner.task_runner: driver plugin has shutdown; attempting to recover task: alloc_id=f48523fe-d89b-3fd7-0675-5a36839d010b task=src driver=dtle
2022-03-25T17:22:05.824+0800 [WARN]  client.driver_mgr: received fingerprint error from driver: driver=dtle error="plugin is shut down"
2022-03-25T17:22:05.824+0800 [ERROR] client.driver_mgr: error receiving stream from TaskStats driver RPC, closing stream: driver=dtle error="rpc error: code = Unavailable desc = transport is closing"
2022-03-25T17:22:05.824+0800 [WARN]  client.driver_mgr: failed to reattach to plugin, starting new instance: driver=dtle err="singleton plugin exited"
2022-03-25T17:22:05.825+0800 [DEBUG] client.driver_mgr: starting plugin: driver=dtle path=/opt/dtle/usr/share/dtle/nomad-plugin/dtle args=[/opt/dtle/usr/share/dtle/nomad-plugin/dtle]
2022-03-25T17:22:05.825+0800 [DEBUG] client.driver_mgr: plugin started: driver=dtle path=/opt/dtle/usr/share/dtle/nomad-plugin/dtle pid=566
2022-03-25T17:22:05.825+0800 [DEBUG] client.driver_mgr: waiting for RPC address: driver=dtle path=/opt/dtle/usr/share/dtle/nomad-plugin/dtle

Output of ./dtle version:**

9.9.9.9-master-89d6f24

在dtle ParseQueryEventFlags() 中,

	case Q_UPDATED_DB_NAMES:
		count := int8(bs[i]) // 得 0xfe=254

导致后续panic.

查MySQL代码 Query_log_event::write():

    *start++ = Q_UPDATED_DB_NAMES;
    dbs =
        (thd->get_binlog_accessed_db_names()->elements <= MAX_DBS_IN_EVENT_MTS)
            ? thd->get_binlog_accessed_db_names()->elements
            : OVER_MAX_DBS_IN_EVENT_MTS;
    ...
      *start++ = dbs;

binlog_event.h:

#define MAX_DBS_IN_EVENT_MTS 16

/**
   When the actual number of databases exceeds MAX_DBS_IN_EVENT_MTS
   the value of OVER_MAX_DBS_IN_EVENT_MTS is is put into the
   mts_accessed_dbs status.
*/
#define OVER_MAX_DBS_IN_EVENT_MTS 254

即254有特殊含义.

[asiroliu]

verify version:
9.9.9.9-master-e903520