go-mysql-org / go-mysql-elasticsearch

Sync MySQL data into elasticsearch
MIT License
4.13k stars 800 forks source link

level=error msg="do ES bulk err invalid character '<' looking for beginning of value, close sync" #215

Open yineng999 opened 6 years ago

yineng999 commented 6 years ago

你好! 同步的时候有时候会停止,报错如下: time="2018-02-26T16:45:46+08:00" level=info msg="save position (mysql-bin.001577, 37929263)" time="2018-02-26T16:46:46+08:00" level=error msg="sync docs err invalid character '<' looking for beginning of value after binlog (mysql-bin.001577, 39846518)" time="2018-02-26T16:46:46+08:00" level=error msg="do ES bulk err invalid character '<' looking for beginning of value, close sync" time="2018-02-26T16:46:46+08:00" level=info msg="context is done with context canceled, closing" time="2018-02-26T16:46:46+08:00" level=info msg="closing river" time="2018-02-26T16:46:46+08:00" level=info msg="closing canal" time="2018-02-26T16:46:46+08:00" level=info msg="syncer is closing..." time="2018-02-26T16:46:46+08:00" level=error msg="close sync with err: sync is been closing..." time="2018-02-26T16:46:46+08:00" level=info msg="syncer is closed" time="2018-02-26T16:46:46+08:00" level=info msg="save position (mysql-bin.001577, 37929263)"

我看提示是说binlog有无效字符,但我打开binlog如下,貌似没有特殊字符:

at 39846487

180226 16:46:01 server id 1572785280 end_log_pos 39846518 CRC32 0x1e27e71c Xid = 3613321400

COMMIT/!/;

at 39846518

180226 16:46:01 server id 1572785280 end_log_pos 39846566 CRC32 0x7ae425df GTID [commit=yes]

SET @@SESSION.GTID_NEXT= 'b2a24a30-f38c-11e6-8701-6c92bf21d7a1:176816173'/!/;

请教这个该是什么原因呀?

yineng999 commented 6 years ago

image

siddontang commented 6 years ago

貌似是发给 ES 的地方有一个非法字符,需要详细的将数据打印出来,才能知道到底是哪一个。

你可以在

if resp, err := r.es.Bulk(reqs); err != nil {
        log.Errorf("sync docs err %v after binlog %s", err, r.canal.SyncedPosition())
        return errors.Trace(err)
    } 

error 里面,详细把 reqs 打印出来看看

yineng999 commented 6 years ago

能看到大量如下日志 Bulk item[106] is &{Action:update Index:es_song_test Type:song ID:2013373 Parent: Data:map[realplaycount:2408 updatetime:2018-03-09T16:30:23+08:00]} Bulk item[107] is &{Action:update Index:es_song_test Type:song ID:6288228 Parent: Data:map[realplaycount:3 updatetime:2018-03-09T16:30:23+08:00]}

貌似是时间格式被当作无效字符了吗?datetime字段不能从mysql同步到ES?

siddontang commented 6 years ago

datetime 可以,你是不是用的 timestamp?你试试最新的代码看看

chenglinjava68 commented 5 years ago

找到原因了吗?