日志:这实在没什么好看的,我只要db1.t2和db1.t3,mydumper也会dump db1.t1
[2020/08/11 09:47:11.078 +08:00] [INFO] [syncer.go:1345] ["meet heartbeat event and then flush jobs"] [task=lancer] [unit="binlog replication"]
[2020/08/11 09:47:11.078 +08:00] [INFO] [syncer.go:2251] ["flush all jobs"] [task=lancer] [unit="binlog replication"] ["global checkpoint"="position: (mysql-bin.000083, 933830490), gtid-set: 41f674be-4176-11e9-a48d-1866da7bf0bd:1-42018157,cfb43ff5-c409-338a-80ea-d7ad05b92a17:1-107464325(flushed position: (mysql-bin.000083, 933830490), gtid-set: cfb43ff5-c409-338a-80ea-d7ad05b92a17:1-107464325,41f674be-4176-11e9-a48d-1866da7bf0bd:1-42018157)"]
[2020/08/11 09:47:11.079 +08:00] [INFO] [syncer.go:839] ["flush checkpoints except for these tables"] [task=lancer] [unit="binlog replication"] [tables="[]"]
[2020/08/11 09:47:11.079 +08:00] [INFO] [syncer.go:842] ["prepare flush sqls"] [task=lancer] [unit="binlog replication"] ["shard meta sqls"="[\"DELETE FROM `dm_meta`.`lancer_syncer_sharding_meta` where source_id=? and target_table_id=?\",\"DELETE FROM `dm_meta`.`lancer_syncer_sharding_meta` where source_id=? and target_table_id=?\",\"DELETE FROM `dm_meta`.`lancer_syncer_sharding_meta` where source_id=? and target_table_id=?\",\"DELETE FROM `dm_meta`.`lancer_syncer_sharding_meta` where source_id=? and target_table_id=?\"]"] ["shard meta arguments"="[[\"lancer01\",\"`dm_lancer`.`t3`\"],[\"lancer01\",\"`dm_lancer`.`t4`\"],[\"lancer01\",\"`dm_lancer`.`t1`\"],[\"lancer01\",\"`dm_lancer`.`t2`\"]]"]
[2020/08/11 09:47:11.098 +08:00] [INFO] [syncer.go:851] ["flushed checkpoint"] [task=lancer] [unit="binlog replication"] [checkpoint="position: (mysql-bin.000083, 933830490), gtid-set: 41f674be-4176-11e9-a48d-1866da7bf0bd:1-42018157,cfb43ff5-c409-338a-80ea-d7ad05b92a17:1-107464325(flushed position: (mysql-bin.000083, 933830490), gtid-set: cfb43ff5-c409-338a-80ea-d7ad05b92a17:1-107464325,41f674be-4176-11e9-a48d-1866da7bf0bd:1-42018157)"]
[2020/08/11 09:47:15.282 +08:00] [INFO] [server.go:493] [request=QueryStatus] [payload="name:\"lancer01\" "]
[2020/08/11 09:47:15.284 +08:00] [INFO] [worker.go:236] ["started sub task"] [component="worker controller"] [config="{\"is-sharding\":true,\"shard-mode\":\"pessimistic\",\"online-ddl-scheme\":\"\",\"case-sensitive\":false,\"name\":\"lancer01\",\"mode\":\"all\",\"ignore-checking-items\":[\"auto_increment_ID\"],\"source-id\":\"lancer01\",\"server-id\":429550044,\"flavor\":\"mysql\",\"meta-schema\":\"dm_meta\",\"heartbeat-update-interval\":1,\"heartbeat-report-interval\":10,\"enable-heartbeat\":false,\"meta\":null,\"Timezone\":\"\",\"relay-dir\":\"relay-dir\",\"use-relay\":false,\"from\":{\"host\":\"10.59.111.113\",\"port\":3306,\"user\":\"dm\",\"max-allowed-packet\":67108864,\"session\":null},\"to\":{\"host\":\"10.59.111.83\",\"port\":4000,\"user\":\"dmwriter\",\"max-allowed-packet\":67108864,\"session\":null},\"route-rules\":[{\"schema-pattern\":\"db1\",\"table-pattern\":\"\",\"target-schema\":\"dm_lancer\",\"target-table\":\"\"}],\"filter-rules\":[],\"mapping-rule\":[],\"black-white-list\":{\"do-tables\":null,\"do-dbs\":[\"~^db1.*\"],\"ignore-tables\":null,\"ignore-dbs\":null},\"mydumper-path\":\"./bin/mydumper\",\"threads\":16,\"chunk-filesize\":\"64\",\"statement-size\":0,\"rows\":0,\"where\":\"\",\"skip-tz-utc\":true,\"extra-args\":\"-B db1 -T1 db1.t2,db1.t3\",\"pool-size\":16,\"dir\":\"./dumped_data.lancer01\",\"meta-file\":\"\",\"worker-count\":16,\"batch\":100,\"queue-size\":1024,\"checkpoint-flush-interval\":30,\"max-retry\":0,\"auto-fix-gtid\":false,\"enable-gtid\":true,\"disable-detect\":false,\"safe-mode\":true,\"enable-ansi-quotes\":false,\"log-level\":\"\",\"log-file\":\"\",\"log-rotate\":\"\",\"pprof-addr\":\"\",\"status-addr\":\"\",\"config-file\":\"\"}"]
[2020/08/11 09:47:15.284 +08:00] [WARN] [syncer.go:2538] ["use system default time location"] [task=lancer01] [unit="binlog replication"]
[2020/08/11 09:47:15.284 +08:00] [INFO] [syncer.go:2540] ["use timezone"] [task=lancer01] [unit="binlog replication"] [location=Local]
[2020/08/11 09:47:15.528 +08:00] [WARN] [dumpling.go:236] ["parsed some unsupported arguments"] [task=lancer01] [unit=dump] [error="unknown shorthand flag: 'T' in -T1"]
[2020/08/11 09:47:15.528 +08:00] [INFO] [dumpling.go:242] ["create dumpling"] [task=lancer01] [unit=dump] [config="{\"Databases\":[\"db1\"],\"Host\":\"10.59.111.113\",\"User\":\"dm\",\"Port\":3306,\"Password\":\"dm\",\"Threads\":4,\"LogLevel\":\"\",\"LogFile\":\"\",\"LogFormat\":\"\",\"Logger\":{},\"FileSize\":67108864,\"StatementSize\":0,\"OutputDirPath\":\"./dumped_data.lancer01\",\"ServerInfo\":{\"ServerType\":0,\"ServerVersion\":null},\"SortByPk\":true,\"Tables\":null,\"StatusAddr\":\"\",\"Snapshot\":\"\",\"Consistency\":\"auto\",\"NoViews\":true,\"NoHeader\":false,\"NoSchemas\":false,\"NoData\":false,\"CsvNullValue\":\"\\\\N\",\"Sql\":\"\",\"TableFilter\":{},\"Rows\":0,\"Where\":\"\",\"FileType\":\"SQL\",\"EscapeBackslash\":true}"]
[2020/08/11 09:47:15.528 +08:00] [WARN] [dumpling.go:244] ["meeting some unsupported arguments"] [task=lancer01] [unit=dump] [argument="[--skip-tz-utc,-B,db1,-T1,db1.t2,db1.t3]"]
[2020/08/11 09:47:15.688 +08:00] [INFO] [sharding_group.go:710] ["execute sql"] [task=lancer01] [unit="binlog replication"] [component="shard group keeper"] [statement="CREATE SCHEMA IF NOT EXISTS `dm_meta`"]
[2020/08/11 09:47:15.691 +08:00] [INFO] [sharding_group.go:728] ["execute sql"] [task=lancer01] [unit="binlog replication"] [component="shard group keeper"] [statement="CREATE TABLE IF NOT EXISTS `dm_meta`.`lancer01_syncer_sharding_meta` (\
\t\tsource_id VARCHAR(32) NOT NULL COMMENT 'replica source id, defined in task.yaml',\
\t\ttarget_table_id VARCHAR(144) NOT NULL,\
\t\tsource_table_id VARCHAR(144) NOT NULL,\
\t\tactive_index INT,\
\t\tis_global BOOLEAN,\
\t\tdata JSON,\
\t\tcreate_time timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,\
\t\tupdate_time timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,\
\t\tUNIQUE KEY uk_source_id_table_id_source (source_id, target_table_id, source_table_id)\
\t)"]
[2020/08/11 09:47:15.706 +08:00] [INFO] [checkpoint.go:605] ["create checkpoint schema"] [task=lancer01] [unit="binlog replication"] [component="remote checkpoint"] [statement="CREATE SCHEMA IF NOT EXISTS `dm_meta`"]
[2020/08/11 09:47:15.709 +08:00] [INFO] [checkpoint.go:626] ["create checkpoint table"] [task=lancer01] [unit="binlog replication"] [component="remote checkpoint"] [statements="[\"CREATE TABLE IF NOT EXISTS `dm_meta`.`lancer01_syncer_checkpoint` (\\
\\t\\t\\tid VARCHAR(32) NOT NULL,\\
\\t\\t\\tcp_schema VARCHAR(128) NOT NULL,\\
\\t\\t\\tcp_table VARCHAR(128) NOT NULL,\\
\\t\\t\\tbinlog_name VARCHAR(128),\\
\\t\\t\\tbinlog_pos INT UNSIGNED,\\
\\t\\t\\tbinlog_gtid VARCHAR(256),\\
\\t\\t\\ttable_info JSON NOT NULL,\\
\\t\\t\\tis_global BOOLEAN,\\
\\t\\t\\tcreate_time timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,\\
\\t\\t\\tupdate_time timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,\\
\\t\\t\\tUNIQUE KEY uk_id_schema_table (id, cp_schema, cp_table)\\
\\t\\t)\"]"]
[2020/08/11 09:47:15.718 +08:00] [INFO] [subtask.go:210] ["start to run"] [subtask=lancer01] [unit=Dump]
[2020/08/11 09:47:15.718 +08:00] [INFO] [worker.go:431] ["load subtask"] [sourceID=lancer01] [task=lancer01]
[2020/08/11 09:47:15.738 +08:00] [INFO] [log.go:70] ["detect server type"] [task=lancer01] [unit=dump] [type=MySQL]
[2020/08/11 09:47:15.738 +08:00] [INFO] [log.go:70] ["detect server version"] [task=lancer01] [unit=dump] [version=5.7.26-log]
[2020/08/11 09:47:16.224 +08:00] [INFO] [dumpling.go:110] ["dump data finished"] [task=lancer01] [unit=dump] ["cost time"=506.217099ms]
[2020/08/11 09:47:16.224 +08:00] [INFO] [subtask.go:276] ["unit process returned"] [subtask=lancer01] [unit=Dump] [stage=Finished] [status={}]
[2020/08/11 09:47:16.224 +08:00] [INFO] [subtask.go:287] ["switching to next unit"] [subtask=lancer01] [unit=Dump]
[2020/08/11 09:47:16.225 +08:00] [INFO] [subtask.go:210] ["start to run"] [subtask=lancer01] [unit=Load]
[2020/08/11 09:47:16.225 +08:00] [INFO] [loader.go:918] ["prepare loading"] [task=lancer01] [unit=load] ["cost time"=332.911µs]
[2020/08/11 09:47:16.229 +08:00] [INFO] [checkpoint.go:158] ["load checkpoint"] [task=lancer01] [unit=load] [component="remote checkpoint"] ["cost time"=4.359029ms]
[2020/08/11 09:47:16.230 +08:00] [INFO] [checkpoint.go:261] ["calculate checkpoint finished."] [task=lancer01] [unit=load] [component="remote checkpoint"] ["finished tables"={}]
[2020/08/11 09:47:16.234 +08:00] [INFO] [loader.go:1108] ["start to create schema"] [task=lancer01] [unit=load] ["schema file"=./dumped_data.lancer01/db1-schema-create.sql]
[2020/08/11 09:47:16.238 +08:00] [ERROR] [baseconn.go:182] ["execute statement failed"] [task=lancer01] [unit=load] [query="CREATE DATABASE `dm_lancer` /*!40100 DEFAULT CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci */;"] [argument="[]"] [error="Error 1007: Can't create database 'dm_lancer'; database exists"]
[2020/08/11 09:47:16.239 +08:00] [ERROR] [db.go:176] ["execute statements failed after retry"] [task=lancer01] [unit=load] [queries="[CREATE DATABASE `dm_lancer` /*!40100 DEFAULT CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci */;]"] [arguments="[]"] [error="[code=10006:class=database:scope=not-set:level=high] execute statement failed: CREATE DATABASE `dm_lancer` /*!40100 DEFAULT CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci */;: Error 1007: Can't create database 'dm_lancer'; database exists"]
[2020/08/11 09:47:16.239 +08:00] [INFO] [loader.go:969] ["database already exists, skip it"] [task=lancer01] [unit=load] ["db schema file"=./dumped_data.lancer01/db1-schema-create.sql]
[2020/08/11 09:47:16.239 +08:00] [INFO] [loader.go:1113] ["finish to create schema"] [task=lancer01] [unit=load] ["schema file"=./dumped_data.lancer01/db1-schema-create.sql]
[2020/08/11 09:47:16.240 +08:00] [INFO] [loader.go:1135] ["start to create table"] [task=lancer01] [unit=load] ["table file"=./dumped_data.lancer01/db1.t3-schema.sql]
[2020/08/11 09:47:16.283 +08:00] [INFO] [server.go:493] [request=QueryStatus] [payload="name:\"lancer01\" "]
[2020/08/11 09:47:16.363 +08:00] [INFO] [loader.go:1140] ["finish to create table"] [task=lancer01] [unit=load] ["table file"=./dumped_data.lancer01/db1.t3-schema.sql]
[2020/08/11 09:47:16.363 +08:00] [INFO] [loader.go:1135] ["start to create table"] [task=lancer01] [unit=load] ["table file"=./dumped_data.lancer01/db1.t1-schema.sql]
[2020/08/11 09:47:16.369 +08:00] [ERROR] [baseconn.go:182] ["execute statement failed"] [task=lancer01] [unit=load] [query="CREATE TABLE `t1` (`id` int(11) NOT NULL AUTO_INCREMENT,`name` text COLLATE utf8mb4_unicode_ci,PRIMARY KEY (`id`)) ENGINE=InnoDB AUTO_INCREMENT=229003 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci;"] [argument="[]"] [error="Error 1050: Table 'dm_lancer.t1' already exists"]
[2020/08/11 09:47:16.370 +08:00] [ERROR] [db.go:176] ["execute statements failed after retry"] [task=lancer01] [unit=load] [queries="[USE `dm_lancer`; CREATE TABLE `t1` (`id` int(11) NOT NULL AUTO_INCREMENT,`name` text COLLATE utf8mb4_unicode_ci,PRIMARY KEY (`id`)) ENGINE=InnoDB AUTO_INCREMENT=229003 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci;]"] [arguments="[]"] [error="[code=10006:class=database:scope=not-set:level=high] execute statement failed: CREATE TABLE `t1` (`id` int(11) NOT NULL AUTO_INCREMENT,`name` text COLLATE utf8mb4_unicode_ci,PRIMARY KEY (`id`)) ENGINE=InnoDB AUTO_INCREMENT=229003 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci;: Error 1050: Table 'dm_lancer.t1' already exists"]
[2020/08/11 09:47:16.370 +08:00] [INFO] [loader.go:982] ["table already exists, skip it"] [task=lancer01] [unit=load] ["table schema file"=./dumped_data.lancer01/db1.t1-schema.sql]
[2020/08/11 09:47:16.370 +08:00] [INFO] [loader.go:1140] ["finish to create table"] [task=lancer01] [unit=load] ["table file"=./dumped_data.lancer01/db1.t1-schema.sql]
[2020/08/11 09:47:16.370 +08:00] [INFO] [loader.go:1135] ["start to create table"] [task=lancer01] [unit=load] ["table file"=./dumped_data.lancer01/db1.t4-schema.sql]
[2020/08/11 09:47:16.486 +08:00] [INFO] [loader.go:1140] ["finish to create table"] [task=lancer01] [unit=load] ["table file"=./dumped_data.lancer01/db1.t4-schema.sql]
[2020/08/11 09:47:16.487 +08:00] [INFO] [loader.go:1135] ["start to create table"] [task=lancer01] [unit=load] ["table file"=./dumped_data.lancer01/db1.t2-schema.sql]
[2020/08/11 09:47:16.722 +08:00] [INFO] [loader.go:1140] ["finish to create table"] [task=lancer01] [unit=load] ["table file"=./dumped_data.lancer01/db1.t2-schema.sql]
[2020/08/11 09:47:16.722 +08:00] [INFO] [loader.go:1174] ["finish to create tables"] [task=lancer01] [unit=load] ["cost time"=492.498175ms]
[2020/08/11 09:47:16.722 +08:00] [INFO] [loader.go:1186] ["all data files have been dispatched, waiting for them finished"] [task=lancer01] [unit=load]
[2020/08/11 09:47:16.722 +08:00] [INFO] [loader.go:217] ["start to restore dump sql file"] [task=lancer01] [unit=load] ["worker ID"=1] ["data file"=dumped_data.lancer01/db1.t1.0.sql]
[2020/08/11 09:47:16.722 +08:00] [INFO] [loader.go:217] ["start to restore dump sql file"] [task=lancer01] [unit=load] ["worker ID"=0] ["data file"=dumped_data.lancer01/db1.t4.0.sql]
[2020/08/11 09:47:16.722 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=3]
[2020/08/11 09:47:16.722 +08:00] [INFO] [checkpoint.go:292] ["initial checkpoint record"] [task=lancer01] [unit=load] [component="remote checkpoint"] [sql="INSERT INTO `dm_meta`.`lancer01_loader_checkpoint` (`id`, `filename`, `cp_schema`, `cp_table`, `offset`, `end_pos`) VALUES(?,?,?,?,?,?)"] [id=lancer01] [filename=db1.t1.0.sql] [schema=db1] [table=t1] [offset=0] ["end position"=49283748]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=8]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=8]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=8]
[2020/08/11 09:47:16.722 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=12]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=12]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=12]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=3]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=3]
[2020/08/11 09:47:16.722 +08:00] [INFO] [loader.go:217] ["start to restore dump sql file"] [task=lancer01] [unit=load] ["worker ID"=2] ["data file"=dumped_data.lancer01/db1.t2.0.sql]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=9]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=9]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=9]
[2020/08/11 09:47:16.723 +08:00] [INFO] [checkpoint.go:292] ["initial checkpoint record"] [task=lancer01] [unit=load] [component="remote checkpoint"] [sql="INSERT INTO `dm_meta`.`lancer01_loader_checkpoint` (`id`, `filename`, `cp_schema`, `cp_table`, `offset`, `end_pos`) VALUES(?,?,?,?,?,?)"] [id=lancer01] [filename=db1.t4.0.sql] [schema=db1] [table=t4] [offset=0] ["end position"=62]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=13]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=13]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=13]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=10]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=10]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=10]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=15]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=15]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=15]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=6]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=6]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=6]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=11]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=11]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=11]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=5]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=5]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=5]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=14]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=14]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=14]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=7]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=7]
[2020/08/11 09:47:16.723 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=7]
[2020/08/11 09:47:16.723 +08:00] [INFO] [checkpoint.go:292] ["initial checkpoint record"] [task=lancer01] [unit=load] [component="remote checkpoint"] [sql="INSERT INTO `dm_meta`.`lancer01_loader_checkpoint` (`id`, `filename`, `cp_schema`, `cp_table`, `offset`, `end_pos`) VALUES(?,?,?,?,?,?)"] [id=lancer01] [filename=db1.t2.0.sql] [schema=db1] [table=t2] [offset=0] ["end position"=89]
[2020/08/11 09:47:16.724 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=4]
[2020/08/11 09:47:16.724 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=4]
[2020/08/11 09:47:16.724 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=4]
[2020/08/11 09:47:16.746 +08:00] [INFO] [loader.go:285] ["data are scanned finished."] [task=lancer01] [unit=load] ["worker ID"=0] ["data file"=dumped_data.lancer01/db1.t4.0.sql] [offset=0]
[2020/08/11 09:47:16.756 +08:00] [INFO] [loader.go:285] ["data are scanned finished."] [task=lancer01] [unit=load] ["worker ID"=2] ["data file"=dumped_data.lancer01/db1.t2.0.sql] [offset=0]
[2020/08/11 09:47:16.767 +08:00] [INFO] [loader.go:149] ["jobs are finished, execution goroutine exits"] [task=lancer01] [unit=load] ["worker ID"=0]
[2020/08/11 09:47:16.767 +08:00] [INFO] [loader.go:234] ["finish to restore dump sql file"] [task=lancer01] [unit=load] ["worker ID"=0] ["data file"=dumped_data.lancer01/db1.t4.0.sql]
[2020/08/11 09:47:16.768 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=0]
[2020/08/11 09:47:16.768 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=0]
[2020/08/11 09:47:16.768 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=0]
[2020/08/11 09:47:16.775 +08:00] [INFO] [loader.go:149] ["jobs are finished, execution goroutine exits"] [task=lancer01] [unit=load] ["worker ID"=2]
[2020/08/11 09:47:16.775 +08:00] [INFO] [loader.go:234] ["finish to restore dump sql file"] [task=lancer01] [unit=load] ["worker ID"=2] ["data file"=dumped_data.lancer01/db1.t2.0.sql]
[2020/08/11 09:47:16.775 +08:00] [INFO] [loader.go:195] ["file queue was closed, main routine exit."] [task=lancer01] [unit=load] ["worker ID"=2]
[2020/08/11 09:47:16.775 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=2]
[2020/08/11 09:47:16.775 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=2]
[2020/08/11 09:47:17.268 +08:00] [INFO] [loader.go:285] ["data are scanned finished."] [task=lancer01] [unit=load] ["worker ID"=1] ["data file"=dumped_data.lancer01/db1.t1.0.sql] [offset=0]
[2020/08/11 09:47:20.194 +08:00] [INFO] [syncer.go:2157] ["binlog replication progress"] [task=lancer] [unit="binlog replication"] ["total binlog size"=1323543] ["last binlog size"=1323508] ["cost time"=30] [bytes/Second=1] ["unsynced binlog size"=0] ["estimate time to catch up"=0]
[2020/08/11 09:47:20.195 +08:00] [INFO] [syncer.go:2182] ["binlog replication status"] [task=lancer] [unit="binlog replication"] [total_events=0] [total_tps=0] [tps=0] [master_position="(mysql-bin.000083, 933830490)"] [master_gtid=41f674be-4176-11e9-a48d-1866da7bf0bd:1-42018157,cfb43ff5-c409-338a-80ea-d7ad05b92a17:1-107464325] [checkpoint="position: (mysql-bin.000083, 933830490), gtid-set: cfb43ff5-c409-338a-80ea-d7ad05b92a17:1-107464325,41f674be-4176-11e9-a48d-1866da7bf0bd:1-42018157(flushed position: (mysql-bin.000083, 933830490), gtid-set: cfb43ff5-c409-338a-80ea-d7ad05b92a17:1-107464325,41f674be-4176-11e9-a48d-1866da7bf0bd:1-42018157)"]
[2020/08/11 09:47:21.081 +08:00] [ERROR] [baseconn.go:182] ["execute statement failed"] [task=lancer01] [unit=load] ["worker ID"=1] [query="INSERT INTO `t1` VALUES\
(1,'sssssssssssssssddddddddddddffffffffffff'),\
(4,'sssssssssssssssddddddddddddffffffffffff'),\
(7,'sssssssssssssssddddddddddddffffffffffff'),\
(10,'sssssssssssssssddddddddddddffffffffffff'),\
(13,'sssssssssssssssddddddddddddffffffffffff'),\
(16,'sssssssssssssssddddddddddddffffffffffff'),\
(19,'sssssssssssssssddddddddddddffffffffffff'),\
(22,'sssssssssssssssddddddddddddffffffffffff'),\
(25,'sssssssssssssssddddddddddddffffffffffff'),\
(28,'sssssssssssssssddddddddddddffffffffffff'),\
(31,'sssssssssssssssddddddddddddffffffffffff'),\
(34,'sssssssssssssssddddddddddddffffffffffff'),\
(37,'sssssssssssssssddddddddddddffffffffffff'),\
(40,'sssssssssssssssddddddddddddffffffffffff'),\
(43,'sssssssssssssssddddddddddddffffffffffff'),\
(46,'sssssssssssssssddddddddddddffffffffffff'),\
(49,'sssssssssssssssddddddddddddffffffffffff'),\
(52,'sssssssssssssssddddddddddddffffffffffff'),\
(55,'sssssssssssssssddddddddddddffffffffffff'),\
(58,'sssssssssssssssddddddddddddffffffffffff'),\
(61,'sssssssssssssssddddddddddddfffffffffff..."] [argument="[]"] [error="Error 1062: Duplicate entry '1' for key 'PRIMARY'"]
[2020/08/11 09:47:21.208 +08:00] [ERROR] [db.go:176] ["execute statements failed after retry"] [task=lancer01] [unit=load] ["worker ID"=1] [queries="[USE `dm_lancer`; INSERT INTO `t1` VALUES\
(1,'sssssssssssssssddddddddddddffffffffffff'),\
(4,'sssssssssssssssddddddddddddffffffffffff'),\
(7,'sssssssssssssssddddddddddddffffffffffff'),\
(10,'sssssssssssssssddddddddddddffffffffffff'),\
(13,'sssssssssssssssddddddddddddffffffffffff'),\
(16,'sssssssssssssssddddddddddddffffffffffff'),\
(19,'sssssssssssssssddddddddddddffffffffffff'),\
(22,'sssssssssssssssddddddddddddffffffffffff'),\
(25,'sssssssssssssssddddddddddddffffffffffff'),\
(28,'sssssssssssssssddddddddddddffffffffffff'),\
(31,'sssssssssssssssddddddddddddffffffffffff'),\
(34,'sssssssssssssssddddddddddddffffffffffff'),\
(37,'sssssssssssssssddddddddddddffffffffffff'),\
(40,'sssssssssssssssddddddddddddffffffffffff'),\
(43,'sssssssssssssssddddddddddddffffffffffff'),\
(46,'sssssssssssssssddddddddddddffffffffffff'),\
(49,'sssssssssssssssddddddddddddffffffffffff'),\
(52,'sssssssssssssssddddddddddddffffffffffff'),\
(55,'sssssssssssssssddddddddddddffffffffffff'),\
(58,'sssssssssssssssddddddddddddffffffffffff'),\
(61,'sssssssssssssssddddd..."] [arguments="[]"] [error="[code=10006:class=database:scope=not-set:level=high] execute statement failed: INSERT INTO `t1` VALUES\
(1,'sssssssssssssssddddddddddddffffffffffff'),\
(4,'sssssssssssssssddddddddddddffffffffffff'),\
(7,'sssssssssssssssddddddddddddffffffffffff'),\
(10,'sssssssssssssssddddddddddddffffffffffff'),\
(13,'sssssssssssssssddddddddddddffffffffffff'),\
(16,'sssssssssssssssddddddddddddffffffffffff'),\
(19,'sssssssssssssssddddddddddddffffffffffff'),\
(22,'sssssssssssssssddddddddddddffffffffffff'),\
(25,'sssssssssssssssddddddddddddffffffffffff'),\
(28,'sssssssssssssssddddddddddddffffffffffff'),\
(31,'sssssssssssssssddddddddddddffffffffffff'),\
(34,'sssssssssssssssddddddddddddffffffffffff'),\
(37,'sssssssssssssssddddddddddddffffffffffff'),\
(40,'sssssssssssssssddddddddddddffffffffffff'),\
(43,'sssssssssssssssddddddddddddffffffffffff'),\
(46,'sssssssssssssssddddddddddddffffffffffff'),\
(49,'sssssssssssssssddddddddddddffffffffffff'),\
(52,'sssssssssssssssddddddddddddffffffffffff'),\
(55,'sssssssssssssssddddddddddddffffffffffff'),\
(58,'sssssssssssssssddddddddddddffffffffffff'),\
(61,'sssssssssssssssddddddddddddfffffffffff...: Error 1062: Duplicate entry '1' for key 'PRIMARY'"]
[2020/08/11 09:47:21.208 +08:00] [INFO] [loader.go:234] ["finish to restore dump sql file"] [task=lancer01] [unit=load] ["worker ID"=1] ["data file"=dumped_data.lancer01/db1.t1.0.sql]
[2020/08/11 09:47:21.208 +08:00] [INFO] [loader.go:191] ["context canceled, main goroutine exits"] [task=lancer01] [unit=load] ["worker ID"=1]
[2020/08/11 09:47:21.208 +08:00] [INFO] [loader.go:119] ["start to close..."] [task=lancer01] [unit=load] ["worker ID"=1]
[2020/08/11 09:47:21.209 +08:00] [INFO] [loader.go:122] ["closed !!!"] [task=lancer01] [unit=load] ["worker ID"=1]
[2020/08/11 09:47:21.208 +08:00] [INFO] [status.go:75] ["progress status of load"] [task=lancer01] [unit=load] [finished_bytes=151] [total_bytes=49283899] [total_file_count=8] [progress="0.00 %"]
[2020/08/11 09:47:21.209 +08:00] [INFO] [loader.go:597] ["all data files have been finished"] [task=lancer01] [unit=load] ["cost time"=4.978893989s]
[2020/08/11 09:47:21.209 +08:00] [INFO] [loader.go:636] ["stop importing data process"] [task=lancer01] [unit=load]
[2020/08/11 09:47:21.209 +08:00] [INFO] [subtask.go:276] ["unit process returned"] [subtask=lancer01] [unit=Load] [stage=Paused] [status="{\"finishedBytes\":151,\"totalBytes\":49283899,\"progress\":\"0.00 %\",\"metaBinlog\":\"(mysql-bin.000083, 933830490)\"}"]
[2020/08/11 09:47:21.209 +08:00] [ERROR] [subtask.go:295] ["unit process error"] [subtask=lancer01] [unit=Load] ["error information"="{\"msg\":\"file db1.t1.0.sql: execute statement failed: INSERT INTO `t1` VALUES\\
(1,'sssssssssssssssddddddddddddffffffffffff'),\\
(4,'sssssssssssssssddddddddddddffffffffffff'),\\
(7,'sssssssssssssssddddddddddddffffffffffff'),\\
(10,'sssssssssssssssddddddddddddffffffffffff'),\\
(13,'sssssssssssssssddddddddddddffffffffffff'),\\
(16,'sssssssssssssssddddddddddddffffffffffff'),\\
(19,'sssssssssssssssddddddddddddffffffffffff'),\\
(22,'sssssssssssssssddddddddddddffffffffffff'),\\
(25,'sssssssssssssssddddddddddddffffffffffff'),\\
(28,'sssssssssssssssddddddddddddffffffffffff'),\\
(31,'sssssssssssssssddddddddddddffffffffffff'),\\
(34,'sssssssssssssssddddddddddddffffffffffff'),\\
(37,'sssssssssssssssddddddddddddffffffffffff'),\\
(40,'sssssssssssssssddddddddddddffffffffffff'),\\
(43,'sssssssssssssssddddddddddddffffffffffff'),\\
(46,'sssssssssssssssddddddddddddffffffffffff'),\\
(49,'sssssssssssssssddddddddddddffffffffffff'),\\
(52,'sssssssssssssssddddddddddddffffffffffff'),\\
(55,'sssssssssssssssddddddddddddffffffffffff'),\\
(58,'sssssssssssssssddddddddddddffffffffffff'),\\
(61,'sssssssssssssssddddddddddddfffffffffff...: Error 1062: Duplicate entry '1' for key 'PRIMARY'\",\"error\":{\"ErrCode\":10006,\"ErrClass\":1,\"ErrScope\":2,\"ErrLevel\":3,\"Message\":\"file db1.t1.0.sql: execute statement failed: INSERT INTO `t1` VALUES\\
(1,'sssssssssssssssddddddddddddffffffffffff'),\\
(4,'sssssssssssssssddddddddddddffffffffffff'),\\
(7,'sssssssssssssssddddddddddddffffffffffff'),\\
(10,'sssssssssssssssddddddddddddffffffffffff'),\\
(13,'sssssssssssssssddddddddddddffffffffffff'),\\
(16,'sssssssssssssssddddddddddddffffffffffff'),\\
(19,'sssssssssssssssddddddddddddffffffffffff'),\\
(22,'sssssssssssssssddddddddddddffffffffffff'),\\
(25,'sssssssssssssssddddddddddddffffffffffff'),\\
(28,'sssssssssssssssddddddddddddffffffffffff'),\\
(31,'sssssssssssssssddddddddddddffffffffffff'),\\
(34,'sssssssssssssssddddddddddddffffffffffff'),\\
(37,'sssssssssssssssddddddddddddffffffffffff'),\\
(40,'sssssssssssssssddddddddddddffffffffffff'),\\
(43,'sssssssssssssssddddddddddddffffffffffff'),\\
(46,'sssssssssssssssddddddddddddffffffffffff'),\\
(49,'sssssssssssssssddddddddddddffffffffffff'),\\
(52,'sssssssssssssssddddddddddddffffffffffff'),\\
(55,'sssssssssssssssddddddddddddffffffffffff'),\\
(58,'sssssssssssssssddddddddddddffffffffffff'),\\
(61,'sssssssssssssssddddddddddddfffffffffff...: Error 1062: Duplicate entry '1' for key 'PRIMARY'\",\"RawCause\":\"Error 1062: Duplicate entry '1' for key 'PRIMARY'\"}}"]
[2020/08/11 09:47:22.753 +08:00] [WARN] [task_checker.go:336] ["task can't auto resume"] [component="task checker"] [task=lancer01]
[2020/08/11 09:47:27.753 +08:00] [WARN] [task_checker.go:333] ["task can't auto resume"] [component="task checker"] [task=lancer01] ["paused duration"=4.999988001s]
[2020/08/11 09:47:32.753 +08:00] [WARN] [task_checker.go:333] ["task can't auto resume"] [component="task checker"] [task=lancer01] ["paused duration"=9.999999952s]
[2020/08/11 09:47:37.753 +08:00] [WARN] [task_checker.go:333] ["task can't auto resume"] [component="task checker"] [task=lancer01] ["paused duration"=14.999945164s]
[2020/08/11 09:47:42.753 +08:00] [WARN] [task_checker.go:333] ["task can't auto resume"] [component="task checker"] [task=lancer01] ["paused duration"=20.000031015s]