tiflow icon indicating copy to clipboard operation
tiflow copied to clipboard

DPANIC with MariaDB 10.6

Open dveeden opened this issue 1 year ago • 4 comments

What did you do?

Setup DM with MariaDB 10.6.11

    [2023/11/29 11:17:55.229 +02:00]
    [DPANIC]
    [tracker.go:206]
    ["unexpected statement type"]
    [task=demo-mariadb-tidb]
    [unit="binlog replication"]
    [component=schema-tracker]
    [task=demo-mariadb-tidb]
    [type=*ast.SetStmt]
    [stack="github.com/pingcap/tiflow/dm/pkg/schema.(*Tracker).Exec\n\tgithub.com/pingcap/tiflow/dm/pkg/schema/tracker.go:206\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).loadTableStructureFromDump\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:3068\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).Run\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:1856\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).Process\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:757"]
    
    [2023/11/29 11:17:55.231 +02:00]
    [INFO]
    [syncer.go:1688]
    ["received ungraceful exit ctx, exit now"]
    [task=demo-mariadb-tidb]
    [unit="binlog replication"]
    panic: interface conversion: ast.StmtNode is *ast.SetStmt, not *ast.CreateTableStmt
    
    goroutine 1807 [running]:
    github.com/pingcap/tiflow/dm/syncer.(*Syncer).loadTableStructureFromDump(0xc000cb7200, {0x4a54438, 0xc00105dd10})
            github.com/pingcap/tiflow/dm/syncer/syncer.go:3079 +0x1ce9
    github.com/pingcap/tiflow/dm/syncer.(*Syncer).Run(0xc000cb7200, {0x4a54438?, 0xc00105dd10?})
            github.com/pingcap/tiflow/dm/syncer/syncer.go:1856 +0xcd6
    github.com/pingcap/tiflow/dm/syncer.(*Syncer).Process(0xc000cb7200, {0x4a54438, 0xc00105dcc0}, 0x0?)
            github.com/pingcap/tiflow/dm/syncer/syncer.go:757 +0x325
    created by github.com/pingcap/tiflow/dm/worker.(*SubTask).run in goroutine 1707
            github.com/pingcap/tiflow/dm/worker/subtask.go:242 +0x53b

What did you expect to see?

No response

What did you see instead?

No response

Versions of the cluster

Master @ 13499f4b366202cb46beba631a66997a62c99884

current status of DM cluster (execute query-status <task-name> in dmctl)

(paste current status of DM cluster here)

dveeden avatar Nov 30 '23 12:11 dveeden

Without any formatting:

[2023/11/30 13:24:16.218 +01:00] [DPANIC] [tracker.go:206] ["unexpected statement type"] [task=demo-mariadb-tidb] [unit="binlog replication"] [component=schema-tracker] [task=demo-mariadb-tidb] [type=*ast.SetStmt] [stack="github.com/pingcap/tiflow/dm/pkg/schema.(*Tracker).Exec\n\tgithub.com/pingcap/tiflow/dm/pkg/schema/tracker.go:206\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).loadTableStructureFromDump\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:3068\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).Run\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:1856\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).Process\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:757"]
[2023/11/30 13:24:16.219 +01:00] [INFO] [syncer.go:1688] ["received ungraceful exit ctx, exit now"] [task=demo-mariadb-tidb] [unit="binlog replication"]
panic: interface conversion: ast.StmtNode is *ast.SetStmt, not *ast.CreateTableStmt

goroutine 2068 [running]:
github.com/pingcap/tiflow/dm/syncer.(*Syncer).loadTableStructureFromDump(0xc000d9c000, {0x4a54438, 0xc003f57720})
	github.com/pingcap/tiflow/dm/syncer/syncer.go:3079 +0x1ce9
github.com/pingcap/tiflow/dm/syncer.(*Syncer).Run(0xc000d9c000, {0x4a54438?, 0xc003f57720?})
	github.com/pingcap/tiflow/dm/syncer/syncer.go:1856 +0xcd6
github.com/pingcap/tiflow/dm/syncer.(*Syncer).Process(0xc000d9c000, {0x4a54438, 0xc003f576d0}, 0x0?)
	github.com/pingcap/tiflow/dm/syncer/syncer.go:757 +0x325
created by github.com/pingcap/tiflow/dm/worker.(*SubTask).run in goroutine 1949
	github.com/pingcap/tiflow/dm/worker/subtask.go:242 +0x53b

dveeden avatar Nov 30 '23 12:11 dveeden

With a small change to show what the SET statement is:

[2023/11/30 13:30:16.896 +01:00] [DPANIC] [tracker.go:206] ["Encountered SET statement"] [task=demo-mariadb-tidb] [unit="binlog replication"] [component=schema-tracker] [task=demo-mariadb-tidb] [stmt="SET FOREIGN_KEY_CHECKS=0"] [stack="github.com/pingcap/tiflow/dm/pkg/schema.(*Tracker).Exec\n\tgithub.com/pingcap/tiflow/dm/pkg/schema/tracker.go:206\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).loadTableStructureFromDump\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:3068\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).Run\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:1856\ngithub.com/pingcap/tiflow/dm/syncer.(*Syncer).Process\n\tgithub.com/pingcap/tiflow/dm/syncer/syncer.go:757"]
[2023/11/30 13:30:16.896 +01:00] [INFO] [syncer.go:1688] ["received ungraceful exit ctx, exit now"] [task=demo-mariadb-tidb] [unit="binlog replication"]
panic: interface conversion: ast.StmtNode is *ast.SetStmt, not *ast.CreateTableStmt

goroutine 2082 [running]:
github.com/pingcap/tiflow/dm/syncer.(*Syncer).loadTableStructureFromDump(0xc000b0e900, {0x4a54478, 0xc0033f57c0})
	github.com/pingcap/tiflow/dm/syncer/syncer.go:3079 +0x1ce9
github.com/pingcap/tiflow/dm/syncer.(*Syncer).Run(0xc000b0e900, {0x4a54478?, 0xc0033f57c0?})
	github.com/pingcap/tiflow/dm/syncer/syncer.go:1856 +0xcd6
github.com/pingcap/tiflow/dm/syncer.(*Syncer).Process(0xc000b0e900, {0x4a54478, 0xc0033f5770}, 0x0?)
	github.com/pingcap/tiflow/dm/syncer/syncer.go:757 +0x325
created by github.com/pingcap/tiflow/dm/worker.(*SubTask).run in goroutine 1952
	github.com/pingcap/tiflow/dm/worker/subtask.go:242 +0x53b
diff --git a/dm/pkg/schema/tracker.go b/dm/pkg/schema/tracker.go
index 9da3f49ff..063498e10 100644
--- a/dm/pkg/schema/tracker.go
+++ b/dm/pkg/schema/tracker.go
@@ -202,6 +202,10 @@ func (tr *Tracker) Exec(ctx context.Context, db string, stmt ast.StmtNode) (errR
        case *ast.TruncateTableStmt:
                ident := ast.Ident{Schema: v.Table.Schema, Name: v.Table.Name}
                return tr.upstreamTracker.TruncateTable(tr.se, ident)
+       case *ast.SetStmt:
+               tr.logger.DPanic("Encountered SET statement",
+                       zap.String("stmt", v.Text()),
+               )
        default:
                tr.logger.DPanic("unexpected statement type", zap.String("type", fmt.Sprintf("%T", v)))
        }

So the statement is SET FOREIGN_KEY_CHECKS=0

dveeden avatar Nov 30 '23 12:11 dveeden

$ find dumped_data.demo-mariadb-tidb/ -type f -exec grep SET\ FOREIGN_KEY_CHECKS {} + | tail -5
dumped_data.demo-mariadb-tidb/performance_schema.user_variables_by_thread-schema.sql:SET FOREIGN_KEY_CHECKS=0;
dumped_data.demo-mariadb-tidb/performance_schema.users-schema.sql:SET FOREIGN_KEY_CHECKS=0;
dumped_data.demo-mariadb-tidb/sys-schema-create.sql:SET FOREIGN_KEY_CHECKS=0;
dumped_data.demo-mariadb-tidb/sys.sys_config-schema.sql:SET FOREIGN_KEY_CHECKS=0;
dumped_data.demo-mariadb-tidb/test-schema-create.sql:SET FOREIGN_KEY_CHECKS=0;
$ cat dumped_data.demo-mariadb-tidb/test-schema-create.sql
/*!40101 SET NAMES binary*/;
SET FOREIGN_KEY_CHECKS=0;
CREATE DATABASE `test` /*!40100 DEFAULT CHARACTER SET latin1 COLLATE latin1_swedish_ci */;

dumped_data.demo-mariadb-tidb.zip

dveeden avatar Nov 30 '23 13:11 dveeden

/severity major

fubinzh avatar Dec 01 '23 02:12 fubinzh

Some notes about how to reproduce this:

MariaDB

podman run --network=host --env MARIADB_ALLOW_EMPTY_ROOT_PASSWORD=1 -it mariadb:10.6 \
--port 3307 \
--log-bin \
--binlog_format=ROW

TiDB

./bin/tidb-server

DM

./bin/dm-master -master-addr 127.0.0.1:8261
./bin/dm-worker -worker-addr 127.0.0.1:8262 -join 127.0.0.1:8261

DM Config

./bin/dmctl --master-addr 127.0.0.1:8261
operate-source create source-mariadb.yaml
start-task task-mariadb.yaml
query-status mariadb-to-tidb

Source

source-id: "mariadb-01"
from:
  host: "127.0.0.1"
  port: 3307
  user: "root"

Task

name: mariadb-to-tidb
mysql-instances:
  - source-id: "mariadb-01"
    block-allow-list: "test"
target-database:
  host: "127.0.0.1"
  port: 4000
  user: "root"
block-allow-list:
  test:
    do-dbs: ["*"]

dveeden avatar May 08 '24 09:05 dveeden