github / github/gh-ost

close sync with err: data len 166 < expected 3587

Open
#623 1 comment 0 reactions 0 assignees View on GitHub
Dominant language
Go
Stars
13.6k
Forks
1.4k
Avg merge
2h 31m
Merged PRs (30d)
4

Description

hi ,
the version is 1.0.40. mysql version is 5.7.20-18-log Percona Server (GPL), Release 18, Revision 7ce54a6deef.
command:
`
gh-ost_v1.0.40 --max-load=Threads_running=32 --critical-load=Threads_running=48 --chunk-size=1000 --throttle-control-replicas="xx:xx,xx:xx" --max-lag-millis=1000 --initially-drop-old-table --initially-drop-ghost-table --initially-drop-socket-file --conf="xx.cnf" --host="xx" --port="xx" --database="xx" --table="a" --verbose --alter=" add index idx_base_cust(base_cust_id)" --switch-to-rbr=false --cut-over=default --assume-rbr=true --exact-rowcount=false --default-retries=3 --critical-load-interval-millis=3000 --panic-flag-file=/tmp/ghost.panic.flag.xx.a.6601652 --postpone-cut-over-flag-file=/tmp/ghost.postpone.flag.xx.a.6601652 --throttle-flag-file=/tmp/ghost.throttle.flag.xx.a.6601652 --execute --allow-on-master
`
the log:
```
Copy: 1227096/1227096 100.0%; Applied: 2; Backlog: 0/1000; Time: 36s(total), 35s(copy); streamer: mysql-bin.000183:4056848; State: migrating; ETA: due
2018-08-09 16:17:37 INFO Reconnecting... Will resume at mysql-bin.000183:907636574
2018/08/09 16:17:37 binlogsyncer.go:75: [info] create BinlogSyncer with config &{99999 mysql xx xx xx xx false false }
2018-08-09 16:17:37 INFO Connecting binlog streamer at mysql-bin.000183:4
2018/08/09 16:17:37 binlogsyncer.go:241: [info] begin to sync binlog from position (mysql-bin.000183, 4)
2018/08/09 16:17:37 binlogsyncer.go:134: [info] register slave for master server 10.xx:xx
2018/08/09 16:17:37 binlogsyncer.go:568: [info] rotate to (mysql-bin.000183, 4)
2018-08-09 16:17:37 INFO rotate to next log name: mysql-bin.000183
2018/08/09 16:17:37 binlogstreamer.go:47: [error] close sync with err: data len 166 < expected 3587
2018-08-09 16:17:37 INFO StreamEvents encountered unexpected error: data len 166 < expected 3587
Copy: 1227096/1227096 100.0%; Applied: 2; Backlog: 0/1000; Time: 37s(total), 35s(copy); streamer: mysql-bin.000183:4062381; State: migrating; ETA: due
Copy: 1227096/1227096 100.0%; Applied: 2; Backlog: 0/1000; Time: 38s(total), 35s(copy); streamer: mysql-bin.000183:4062381; State: migrating; ETA: due
2018-08-09 16:17:39 ERROR Timeout while waiting for events up to lock
2018-08-09 16:17:39 ERROR 2018-08-09 16:17:39 ERROR Timeout while waiting for events up to lock
2018-08-09 16:17:39 INFO Looking for magic cut-over table
2018-08-09 16:17:39 INFO Will now proceed to drop magic table and unlock tables
2018-08-09 16:17:39 INFO Dropping magic cut-over table
2018-08-09 16:17:39 INFO Dropping magic cut-over table
2018-08-09 16:17:39 INFO Droppping table `xx`.`_a_del`
2018-08-09 16:17:39 INFO Table dropped
2018-08-09 16:17:39 INFO Releasing lock from `xx`.`a`, `xx`.`_a_del`
2018-08-09 16:17:39 INFO Tables unlocked
Copy: 1227096/1227096 100.0%; Applied: 2; Backlog: 0/1000; Time: 39s(total), 35s(copy); streamer: mysql-bin.000183:4062381; State: migrating; ETA: due
2018-08-09 16:17:40 INFO Grabbing voluntary lock: gh-ost.8482269.lock
2018-08-09 16:17:40 INFO Setting LOCK timeout as 6 seconds
2018-08-09 16:17:40 INFO Looking for magic cut-over table
2018-08-09 16:17:40 INFO Creating magic cut-over table `xx`.`_a_del`
2018-08-09 16:17:40 INFO Magic cut-over table created
2018-08-09 16:17:40 INFO Locking `xx`.`a`, `xx`.`_a_del`
2018-08-09 16:17:40 INFO Tables locked
2018-08-09 16:17:40 INFO Session locking original & magic tables is 8482269
2018-08-09 16:17:40 INFO Writing changelog state: AllEventsUpToLockProcessed:1533802660582469107
2018-08-09 16:17:40 INFO Waiting for events up to lock
Copy: 1227096/1227096 100.0%; Applied: 2; Backlog: 0/1000; Time: 40s(total), 35s(copy); streamer: mysql-bin.000183:4062381; State: migrating; ETA: due
Copy: 1227096/1227096 100.0%; Applied: 2; Backlog: 0/1000; Time: 41s(total), 35s(copy); streamer: mysql-bin.000183:4062381; State: migrating; ETA: due
2018-08-09 16:17:42 FATAL 4 successive failures in streamer reconnect at coordinates mysql-bin.000183:4
```
the table :
```
CREATE TABLE `a` (
`id` bigint(20) NOT NULL AUTO_INCREMENT ,
`tenant_id` int(10) DEFAULT '0' ,
`biz_line_id` int(10) NOT NULL DEFAULT '0' ,
`customer_type_id` int(10) NOT NULL DEFAULT '0' ,
`base_cust_id` bigint(20) NOT NULL ,
`cust_id` bigint(20) NOT NULL,
`sub_biz_line_id` int(10) NOT NULL DEFAULT '0' ,
`is_deleted` tinyint(1) DEFAULT '0' ,
`gmt_created` datetime DEFAULT NULL ,
`creator` int(10) DEFAULT '0' ,
`gmt_modified` datetime DEFAULT NULL ,
`modifier` int(10) DEFAULT '0' ,
PRIMARY KEY (`id`),
UNIQUE KEY `uk_cust_sub_biz_line` (`cust_id`,`sub_biz_line_id`),
KEY `idx_sub_biz_line_tenant_type` (`sub_biz_line_id`,`biz_line_id`,`tenant_id`,`customer_type_id`),
KEY `idx_base_cust` (`base_cust_id`)
) ENGINE=InnoDB AUTO_INCREMENT=1338565 DEFAULT CHARSET=utf8mb4
```
I have run this command about 3 times with both release code and the latest master code. Is there and clues about what happened and how to fix it? Thanks!

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.