DM Task Creation Failed: Failed to Create Schema Tracker

translator_bot · June 23, 2024, 8:04am

Note:
This topic has been translated from a Chinese forum by GPT and might contain errors.

Original topic: DM任务创建失败failed to create schema tracker

| username: sgjr

【TiDB Usage Environment】Production
【TiDB Version】DM2.0.6, TiDB5.1.4, MySQL5.7.28
【Encountered Issue】Failed to create dm-task
【Reproduction Path】What operations were performed to encounter the issue
【Issue Phenomenon and Impact】
【Attachments】

Relevant logs, configuration files, Grafana monitoring (https://metricstool.pingcap.com/)
- dm-task configuration file

name: "210021_1659407811"
# Full + Incremental (all) synchronization mode
task-mode: all
meta-schema: dm_meta
online-ddl-scheme: "gh-ost"
# Downstream TiDB configuration information
target-database:
  host: "10.xxxx"
  port: 3306
  user: "user"
  password: "xxxx"

# Configuration of all upstream MySQL instances required for the current data synchronization task

block-allow-list:
  rule-1:
    do-tables:
    - db-name: "os-server-test"
      tbl-name: "login_entry_points"

filters:
  filter-01:
    schema-pattern: "os-server-test"
    table-pattern: login_entry_points
    events:
    - delete
    - drop table
    sql-pattern: []
    action: Ignore
  filter-02:
    schema-pattern: '*'
    table-pattern: ""
    events: []
    sql-pattern:
    - ALTER\s+TABLE[\s\S]*ADD\s+PARTITION
    - ALTER\s+TABLE[\s\S]*DROP\s+PARTITION
    action: Ignore

mysql-instances:
-
  source-id: "os-server-test"
  block-allow-list: "rule-1"
  filter-rules: ["filter-01", "filter-02"]
  mydumper-config-name: "global"
  syncer-config-name: "global"
  loader-config-name: "global"

# Global configuration for block-allow list, referenced by each instance through the configuration item name

# Global configuration for Mydumper, referenced by each instance through the configuration item name
mydumpers:
  global:
    chunk-filesize: 64
    threads: 4
loaders:
  global:
    pool-size: 32

syncers:
  global:
    worker-count: 64
    batch: 3000
    safe-mode: true

TiUP Cluster Display information
TiUP Cluster Edit config information
TiDB-Overview monitoring
Corresponding module Grafana monitoring (if any, such as BR, TiDB-binlog, TiCDC, etc.)
Corresponding module logs (including logs 1 hour before and after the issue)

[2022/08/02 19:52:08.474 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:52:39.475 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:53:10.477 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:53:41.478 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:53:45.449 +08:00] [INFO] [config.go:599] ["detect server type"] [task=210021_1659407811] [unit="binlog replication"] [scope=upstream] [type=MySQL]
[2022/08/02 19:53:45.449 +08:00] [INFO] [config.go:618] ["detect server version"] [task=210021_1659407811] [unit="binlog replication"] [scope=upstream] [version=5.7.28-log]
[2022/08/02 19:53:46.994 +08:00] [INFO] [config.go:599] ["detect server type"] [task=210021_1659407811] [unit="binlog replication"] [scope=downstream] [type=TiDB]
[2022/08/02 19:53:46.994 +08:00] [INFO] [config.go:618] ["detect server version"] [task=210021_1659407811] [unit="binlog replication"] [scope=downstream] [version=5.1.4]
[2022/08/02 19:53:46.994 +08:00] [ERROR] [baseconn.go:105] ["query statement failed"] [component=schema-tracker] [task=210021_1659407811] [query="SHOW VARIABLES LIKE 'tidb_skip_utf8_check'"] [argument="[]"] [error="context deadline exceeded"]
[2022/08/02 19:53:46.995 +08:00] [INFO] [rollback.go:59] ["rolling back"] [functon=close-DBs] [onwer=syncer]
[2022/08/02 19:53:46.996 +08:00] [INFO] [loader.go:787] ["stop importing data process"] [task=210021_1659407811] [unit=load]
[2022/08/02 19:53:46.996 +08:00] [ERROR] [subtask.go:198] ["fail to initial subtask"] [subtask=210021_1659407811] [error="[code=44012:class=schema-tracker:scope=internal:level=high], Message: fail to initial unit Sync of subtask 210021_1659407811 : failed to create schema tracker, RawCause: context deadline exceeded"]
[2022/08/02 19:53:48.156 +08:00] [INFO] [worker.go:476] ["auto_resume sub task"] [component="worker controller"] [task=210021_1659407811]
[2022/08/02 19:53:48.156 +08:00] [INFO] [syncer.go:3294] ["use timezone"] [task=210021_1659407811] [unit="binlog replication"] [location=UTC]
[2022/08/02 19:53:50.099 +08:00] [INFO] [dumpling.go:300] ["found upstream SQL mode"] [task=210021_1659407811] [unit=dump] ["SQL mode"=ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION]
[2022/08/02 19:53:50.099 +08:00] [INFO] [dumpling.go:67] ["create dumpling"] [task=210021_1659407811] [unit=dump] [config="{\"s3\":{\"endpoint\":\"\",\"region\":\"\",\"storage-class\":\"\",\"sse\":\"\",\"sse-kms-key-id\":\"\",\"acl\":\"\",\"access-key\":\"\",\"secret-access-key\":\"\",\"provider\":\"\",\"force-path-style\":false,\"use-accelerate-endpoint\":false},\"gcs\":{\"endpoint\":\"\",\"storage-class\":\"\",\"predefined-acl\":\"\",\"credentials-file\":\"\"},\"AllowCleartextPasswords\":false,\"SortByPk\":true,\"NoViews\":true,\"NoHeader\":false,\"NoSchemas\":false,\"NoData\":false,\"CompleteInsert\":true,\"TransactionalConsistency\":true,\"EscapeBackslash\":true,\"DumpEmptyDatabase\":true,\"PosAfterConnect\":false,\"CompressType\":0,\"Host\":\"mpay-app16-os-in.i.nease.net\",\"Port\":16388,\"Threads\":4,\"User\":\"root\",\"Security\":{\"CAPath\":\"\",\"CertPath\":\"\",\"KeyPath\":\"\"},\"LogLevel\":\"\",\"LogFile\":\"\",\"LogFormat\":\"\",\"OutputDirPath\":\"./dumped_data.210021_1659407811\",\"StatusAddr\":\"\",\"Snapshot\":\"\",\"Consistency\":\"auto\",\"CsvNullValue\":\"\\\\N\",\"SQL\":\"\",\"CsvSeparator\":\"\",\"CsvDelimiter\":\"\",\"Databases\":null,\"Where\":\"\",\"FileType\":\"\",\"ServerInfo\":{\"ServerType\":0,\"ServerVersion\":null},\"Rows\":200000,\"ReadTimeout\":0,\"TiDBMemQuotaQuery\":0,\"FileSize\":67108864,\"StatementSize\":1000000,\"SessionParams\":{\"time_zone\":\"+00:00\"},\"Tables\":null}"]
[2022/08/02 19:53:54.209 +08:00] [INFO] [loader.go:540] ["loader's sql_mode is"] [task=210021_1659407811] [unit=load] [sqlmode=NO_ENGINE_SUBSTITUTION,ALLOW_INVALID_DATES,NO_AUTO_VALUE_ON_ZERO,ONLY_FULL_GROUP_BY,IGNORE_SPACE]
[2022/08/02 19:56:06.071 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload=]
[2022/08/02 19:56:28.309 +08:00] [INFO] [config.go:599] ["detect server type"] [task=210021_1659407811] [unit="binlog replication"] [scope=upstream] [type=MySQL]
[2022/08/02 19:56:28.309 +08:00] [INFO] [config.go:618] ["detect server version"] [task=210021_1659407811] [unit="binlog replication"] [scope=upstream] [version=5.7.28-log]
[2022/08/02 19:56:29.853 +08:00] [INFO] [config.go:599] ["detect server type"] [task=210021_1659407811] [unit="binlog replication"] [scope=downstream] [type=TiDB]
[2022/08/02 19:56:29.854 +08:00] [INFO] [config.go:618] ["detect server version"] [task=210021_1659407811] [unit="binlog replication"] [scope=downstream] [version=5.1.4]
[2022/08/02 19:56:29.854 +08:00] [ERROR] [baseconn.go:105] ["query statement failed"] [component=schema-tracker] [task=210021_1659407811] [query="SHOW VARIABLES LIKE 'tidb_skip_utf8_check'"] [argument="[]"] [error="context deadline exceeded"]
[2022/08/02 19:56:29.854 +08:00] [INFO] [rollback.go:59] ["rolling back"] [functon=close-DBs] [onwer=syncer]
[2022/08/02 19:56:29.855 +08:00] [INFO] [loader.go:787] ["stop importing data process"] [task=210021_1659407811] [unit=load]
[2022/08/02 19:56:29.855 +08:00] [ERROR] [subtask.go:198] ["fail to initial subtask"] [subtask=210021_1659407811] [error="[code=44012:class=schema-tracker:scope=internal:level=high], Message: fail to initial unit Sync of subtask 210021_1659407811 : failed to create schema tracker, RawCause: context deadline exceeded"]
[2022/08/02 19:56:29.855 +08:00] [INFO] [task_checker.go:401] ["dispatch auto resume task"] [component="task checker"] [task=210021_1659407811]
[2022/08/02 19:56:29.855 +08:00] [WARN] [task_checker.go:393] ["backoff skip auto resume task"] [component="task checker"] [task=210021_1659407811] [latestResumeTime=2022/08/02 19:56:29.855 +08:00] [duration=1.517956931s]
[2022/08/02 19:56:33.156 +08:00] [INFO] [worker.go:476] ["auto_resume sub task"] [component="worker controller"] [task=210021_1659407811]
[2022/08/02 19:56:33.156 +08:00] [INFO] [syncer.go:3294] ["use timezone"] [task=210021_1659407811] [unit="binlog replication"] [location=UTC]
[2022/08/02 19:56:35.025 +08:00] [INFO] [dumpling.go:300] ["found upstream SQL mode"] [task=210021_1659407811] [unit=dump] ["SQL mode"=ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION]
[2022/08/02 19:56:35.025 +08:00] [INFO] [dumpling.go:67] ["create dumpling"] [task=210021_1659407811] [unit=dump] [config="{\"s3\":{\"endpoint\":\"\",\"region\":\"\",\"storage-class\":\"\",\"sse\":\"\",\"sse-kms-key-id\":\"\",\"acl\":\"\",\"access-key\":\"\",\"secret-access-key\":\"\",\"provider\":\"\",\"force-path-style\":false,\"use-accelerate-endpoint\":false},\"gcs\":{\"endpoint\":\"\",\"storage-class\":\"\",\"predefined-acl\":\"\",\"credentials-file\":\"\"},\"AllowCleartextPasswords\":false,\"SortByPk\":true,\"NoViews\":true,\"NoHeader\":false,\"NoSchemas\":false,\"NoData\":false,\"CompleteInsert\":true,\"TransactionalConsistency\":true,\"EscapeBackslash\":true,\"DumpEmptyDatabase\":true,\"PosAfterConnect\":false,\"CompressType\":0,\"Host\":\"mpay-app16-os-in.i.nease.net\",\"Port\":16388,\"Threads\":4,\"User\":\"root\",\"Security\":{\"CAPath\":\"\",\"CertPath\":\"\",\"KeyPath\":\"\"},\"LogLevel\":\"\",\"LogFile\":\"\",\"LogFormat\":\"\",\"OutputDirPath\":\"./dumped_data.210021_1659407811\",\"StatusAddr\":\"\",\"Snapshot\":\"\",\"Consistency\":\"auto\",\"CsvNullValue\":\"\\\\N\",\"SQL\":\"\",\"CsvSeparator\":\"\",\"CsvDelimiter\":\"\",\"Databases\":null,\"Where\":\"\",\"FileType\":\"\",\"ServerInfo\":{\"ServerType\":0,\"ServerVersion\":null},\"Rows\":200000,\"ReadTimeout\":0,\"TiDBMemQuotaQuery\":0,\"FileSize\":67108864,\"StatementSize\":1000000,\"SessionParams\":{\"time_zone\":\"+00:00\"},\"Tables\":null}"]
[2022/08/02 19:56:39.146 +08:00] [INFO] [loader.go:540] ["loader's sql_mode is"] [task=210021_1659407811] [unit=load] [sqlmode=NO_ENGINE_SUBSTITUTION,ALLOW_INVALID_DATES,NO_AUTO_VALUE_ON_ZERO,ONLY_FULL_GROUP_BY,IGNORE_SPACE]
[2022/08/02 19:57:02.696 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:57:02.697 +08:00] [INFO] [worker.go:660] ["receive subtask stage change"] [stage="{\"expect\":0,\"source\":\"mpay-os-server-test\",\"task\":\"210021_1659407811\"}"] ["is deleted"=true]
[2022/08/02 19:57:33.699 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:58:04.700 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:58:35.701 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:58:52.669 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload=]
[2022/08/02 19:59:06.702 +08:00] [INFO] [server.go:753] [request=QueryStatus] [payload="name:\"210021_1659407811\" "]
[2022/08/02 19:59:13.165 +08:00] [INFO] [config.go:599] ["detect server type"] [task=210021_1659407811] [unit="binlog replication"] [scope=upstream] [type=MySQL]
[2022/08/02 19:59:13.165 +08:00] [INFO] [config.go:618] ["detect server version"] [task=210021_1659407811] [unit="binlog replication"] [scope=upstream] [version=5.7.28-log]
[2022/08/02 19:59:14.714 +08:00] [INFO] [config.go:599] ["detect server type"] [task=210021_1659407811] [unit="binlog replication"] [scope=downstream] [type=TiDB]
[2022/08/02 19:59:14.714 +08:00] [INFO] [config.go:618] ["detect server version"] [task=210021_1659407811] [unit="binlog replication"] [scope=downstream] [version=5.1.4]
[2022/08/02 19:59:14.714 +08:00] [ERROR] [baseconn.go:105] ["query statement failed"] [component=schema-tracker] [task=210021_1659407811] [query="SHOW VARIABLES LIKE 'tidb_skip_utf8_check'"] [argument="[]"] [error="context deadline exceeded"]
[2022/08/02 19:59:14.714 +08:00] [INFO]

translator_bot · June 23, 2024, 8:04am

| username: xfworld | Original post link

What kind of permissions are given? Even executing this can fail…

translator_bot · June 23, 2024, 8:04am

| username: sgjr | Original post link

It has nothing to do with permissions; all permissions are set to all privileges.

Upstream MySQL permissions

image693×293 22.4 KB
Downstream TiDB permissions

image949×298 25.3 KB

translator_bot · June 23, 2024, 8:04am

| username: cheng | Original post link

Check the configuration file, then try restarting.

translator_bot · June 23, 2024, 8:04am

| username: sgjr | Original post link

The configuration file has been posted above, and I haven’t found anything wrong with it so far. I’ve tried restarting many times, but it always gets stuck at the same point.

translator_bot · June 23, 2024, 8:04am

| username: xfworld | Original post link

Are any of the following limitations not met?

I suggest taking a look.

translator_bot · June 23, 2024, 8:04am

| username: sgjr | Original post link

MySQL version is 5.7.28, and the character set of the upstream table is utf8mb4.

translator_bot · June 23, 2024, 8:04am

| username: sgjr | Original post link

To add, changing the task-mode to full works normally, but changing it to all or incremental causes an exception.

translator_bot · June 23, 2024, 8:04am

| username: Min_Chen | Original post link

Hi, from the logs it appears that the execution timed out. Please check the network condition from the worker to the downstream, as well as the response time performance of the downstream TiDB.

translator_bot · June 23, 2024, 8:04am

| username: sgjr | Original post link

I found the cause of the problem. It was due to the worker-count setting of syncers being too large. After reducing it, everything returned to normal.

translator_bot · June 23, 2024, 8:04am

| username: system | Original post link

This topic will be automatically closed 60 days after the last reply. No new replies are allowed.