DM同步异常退出:[error="io.CopyN failed. err unexpected EOF, copied 0, expected 79: connection was bad"]

【环境说明】
上游(阿里云RDS):mysql 5.6.16-log
下游TiDB:v4.0.13
DM版本:v2.0.4

【DDL操作】
表结构:
CREATE TABLE mc_activity_assist_support (
id bigint(20) unsigned NOT NULL AUTO_INCREMENT,
activity_id bigint(20) NOT NULL
cycle_no varchar(100) NOT NULL,
city_code varchar(20) NOT NULL,
user_no bigint(20) NOT NULL,
user_phone varchar(15) NOT NULL DEFAULT ‘’ ,
launch_user_no bigint(20) NOT NULL ,
launch_user_phone varchar(15) NOT NULL DEFAULT ‘’ ,
user_type tinyint(3) unsigned NOT NULL DEFAULT ‘2’ ,
nick_name varchar(255) NOT NULL DEFAULT ‘’,
headimg varchar(255) NOT NULL DEFAULT ‘’ ,
assist_status tinyint(3) unsigned NOT NULL DEFAULT ‘0’ ,
snapshot_info text DEFAULT NULL ,
award_info text DEFAULT NULL,
create_time timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT ‘创建时间’,
update_time timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT ‘更新时间’,
PRIMARY KEY (id),
KEY idx_activity_user (activity_id,cycle_no,user_no,user_type),
KEY idx_activity_lanuch_user (activity_id,cycle_no,launch_user_no,user_type),
KEY idx_create_time (create_time),
KEY idx_update_time (update_time),
KEY idx_activity_phone (activity_id,user_phone),
KEY idx_activity_launch_phone (activity_id,launch_user_phone),
KEY idx_activity_user_no (activity_id,user_no),
KEY idx_activity_launch_user_no (activity_id,launch_user_no)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin AUTO_INCREMENT=8279262;

使用gh-ost添加如下索引:
ALTER TABLE marketing_center.mc_activity_assist_support ADD INDEX idx_activity_create_time(activity_id, create_time)

【复制报错】
[2021/08/08 02:19:26.702 +08:00] [ERROR] [streamer_controller.go:259] [“meet error when get binlog event”] [task=dm-rds_master] [unit=“binlog replication”] [error=“io.CopyN failed. err unexpected EOF, copied 0, expected 79: connection was bad”] [errorVerbose=“connection was bad
github.com/go-mysql-org/go-mysql/mysql.init
\t/go/pkg/mod/github.com/go-mysql-org/go-mysql@v1.1.3-0.20210519094347-5ec8d511f5be/mysql/error.go:10
runtime.doInit
\t/usr/local/go/src/runtime/proc.go:5222
runtime.doInit
\t/usr/local/go/src/runtime/proc.go:5217
runtime.doInit
\t/usr/local/go/src/runtime/proc.go:5217
runtime.doInit
\t/usr/local/go/src/runtime/proc.go:5217
runtime.main
\t/usr/local/go/src/runtime/proc.go:190
runtime.goexit
\t/usr/local/go/src/runtime/asm_amd64.s:1357
io.CopyN failed. err unexpected EOF, copied 0, expected 79
github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacketTo
\t/go/pkg/mod/github.com/go-mysql-org/go-mysql@v1.1.3-0.20210519094347-5ec8d511f5be/packet/conn.go:151
github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacketReuseMem
\t/go/pkg/mod/github.com/go-mysql-org/go-mysql@v1.1.3-0.20210519094347-5ec8d511f5be/packet/conn.go:98
github.com/go-mysql-org/go-mysql/packet.(*Conn).ReadPacket
\t/go/pkg/mod/github.com/go-mysql-org/go-mysql@v1.1.3-0.20210519094347-5ec8d511f5be/packet/conn.go:90
github.com/go-mysql-org/go-mysql/replication.(*BinlogSyncer).onStream
\t/go/pkg/mod/github.com/go-mysql-org/go-mysql@v1.1.3-0.20210519094347-5ec8d511f5be/replication/binlogsyncer.go:662
runtime.goexit
\t/usr/local/go/src/runtime/asm_amd64.s:1357”]
[2021/08/08 02:19:26.702 +08:00] [ERROR] [syncer.go:1507] [“fail to fetch binlog”] [task=dm-rds_master] [unit=“binlog replication”] [error=“io.CopyN failed. err unexpected EOF, copied 0, expected 79: connection was bad”]
详细见日志:worker.log (653.7 KB)

【问题】
从数据库监控上看当时并没有发现数据库指标异常,报错时binlog文件也是正常的,没有损坏的情况;出现这个中断一般是什么导致的?是否是触发了某个bug?

附binlog情况:

1 个赞

建议优先检查一下网络和下游 TiDB 集群状态,连接的 TiDB Server 是否发生过相关重启问题。

网络和下游TiDB没有什么异常,所有指标都看过了,都是正常的

看一下 tidb server 是否有重启,可以看一下 tidb log 和 dmsg 日志看看。

没有重启,02:19:25时DDL结束了,02:19:26复制异常退出了,相关日志如下:

麻烦发一下对应的 DM task 配置文件看一下哈。

task.yaml (3.0 KB)

请问 DDL 执行了多久?如果 DDL 太慢的话,DM 在一些内部缓冲区填满之后就无法从上游消费数据,上游会在超时后关闭连接。MySQL 的 net_write_timeout 变量是控制这个超时的

对于这个错误可以直接恢复任务的

在上游RDS中DDL使用gh-ost执行的,在TiDB中大概4分钟执行完。mysql变量如下:

– DM 在一些内部缓冲区填满之后就无法从上游消费数据
就是说DM的DML操作会被DDL操作堵塞吗?那这样如果是大表的话,是不是会有大的延时?

是会引起延迟

这个异常退出是超时导致的吗?不是有多个线程复制的吗,一般来说加索引不应该堵塞dml操作的吧?

这个问题是可以复现的,加索引会堵塞DML,加索引时间长的话,会异常退出并自动恢复。
worker.log (91.8 KB)

建议:加索引不会对数据同步造成影响,不应该采用堵塞的方式执行,对大表同步来说这个延迟是不可接受的,希望可以修复这个问题。

也碰到这个问题了,报错一样,但是没有做DDL操作,同步过程中,报的错

fail to kill last connection, Message: database driver error, RawCause: Error 1094: Unknown threat id:xxxx, Workaround:Please check the database connection and the database config in configuration file.

怎么解决啊

麻烦创建一个新的帖子吧,目前看问题比较可能不一样。

这个我提了issue,可以关注下:https://github.com/pingcap/dm/issues/1974

此话题已在最后回复的 1 分钟后被自动关闭。不再允许新回复。