NewUpdateMsgs panic

[recall704]

1. source type: mysql
2. target type: mysql
3. migrate type: mysqlstream

[recall704]

				case replication.UPDATE_ROWS_EVENTv0, replication.UPDATE_ROWS_EVENTv1, replication.UPDATE_ROWS_EVENTv2:
					if isBinlogChecker {
						log.Debug(".")
					} else {
						log.Debugf("[binlogTailer] Update rows with: schemaName: %v, tableName: %v", schemaName, tableName)
					}

					log.Infof("[binlogTailer] NewUpdateMsgs with binlog: %x", ev)
					msgs, err := NewUpdateMsgs(
						tailer.cfg.Source.Host,
						schemaName,
						tableName,
						int64(e.Header.Timestamp),
						received,
						ev,
						tableDef)

them I add a log before NewUpdateMsgs like this log.Infof("[binlogTailer] NewUpdateMsgs with binlog: %x", ev)

[recall704]

logs

time="2019-12-20T10:50:49+08:00" level=info msg="[binlogTailer] NewUpdateMsgs with binlog: &{2 6 map[186:c00026ed20] %!x(bool=true) c00026ed20 186 1  4 ff ff [[65303662383231342d383163352d343331392d39
163362d333031316530613837646232 14 323031392d31322d32302031303a35303a30332e343630373836202b3030303020555443 323031392d31322d32302031303a35303a30332e343735303238202b3030303020555443[] [6530366238323134
d383163352d343331392d396163362d333031316530613837646232 15 323031392d31322d32302031303a35303a30362e343630343331202b3030303020555443 323031392d31322d32302031303a35303a30362e343734363931202b303030302055
5443[]] %!x(bool=true) 0 %!x(bool=false) %!x(bool=false)}"
panic: runtime error: slice bounds out of range

goroutine 71 [running]:
github.com/OneOfOne/xxhash.(*XXHash64).Sum64(0xc0000beae0, 0xc000d8c6a0)
        /go/src/github.com/OneOfOne/xxhash/xxhash_unsafe.go:214 +0x30e
github.com/mitchellh/hashstructure.(*walker).visit(0xc000e4cd00, 0x2aee920, 0xc00099e310, 0x194, 0x0, 0xc00099e310, 0x194, 0x0)
        /go/src/github.com/mitchellh/hashstructure/hashstructure.go:322 +0x16bd
github.com/mitchellh/hashstructure.(*walker).visit(0xc000e4cd00, 0x29d9240, 0xc000326d20, 0x97, 0x0, 0x0, 0x0, 0xc000032380)
        /go/src/github.com/mitchellh/hashstructure/hashstructure.go:304 +0x9c8
github.com/mitchellh/hashstructure.Hash(0x29d9240, 0xc000326d20, 0x48566c0, 0xc000326d20, 0x5, 0xc00099e300)
        /go/src/github.com/mitchellh/hashstructure/hashstructure.go:89 +0x16b
github.com/moiot/gravity/pkg/inputs/mysqlstream.dataHash(0xc0014648f5, 0xb, 0xc0013e7d80, 0x11, 0x2e59f59, 0x7, 0xc0004081e0, 0x1, 0x1, 0xc000af9e00, ...)
        /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:475 +0x253
github.com/moiot/gravity/pkg/inputs/mysqlstream.dataHashForUKChange(0xc0014648f5, 0xb, 0xc0013e7d80, 0x11, 0x2e59f59, 0x7, 0xc0004081e0, 0x1, 0x1, 0xc000af9e30, ...)
        /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:435 +0x105
github.com/moiot/gravity/pkg/inputs/mysqlstream.GenerateDataHashes(0xc0014648f5, 0xb, 0xc0013e7d80, 0x11, 0xc0016de000, 0xc000af9e30, 0xc000af9e00, 0x2a36a80, 0x2af0d01, 0xc000849420)
        /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:408 +0x3cb
github.com/moiot/gravity/pkg/inputs/mysqlstream.GenerateDMLDepHashes(0xc0011acb60, 0xc000c57dd0, 0xc000995560, 0xc000af9e00, 0xc000af9e90)
        /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:390 +0x7f
github.com/moiot/gravity/pkg/inputs/mysqlstream.NewUpdateMsgs(0xc00005bc50, 0x28, 0xc0019897e5, 0xb, 0xc000d8c680, 0x11, 0x5de0d11c, 0xbf705872ea53d189, 0xbeea9b2f0, 0x4bdc6e0, ...)
        /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:167 +0x1696
github.com/moiot/gravity/pkg/inputs/mysqlstream.(*BinlogTailer).Start.func1(0xc000486200, 0xc000e24008, 0xc00103a4b0, 0xc0013bf3e8)
        /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/binlog_tailer.go:383 +0x2326
created by github.com/moiot/gravity/pkg/inputs/mysqlstream.(*BinlogTailer).Start
        /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/binlog_tailer.go:150 +0x35c

[Ryan-Git]

could you print the key (at mysqlstream/msg.go:475) so we can check why it fails? It seems there's some problem with xxhash.

[recall704]

code

# mysqlstream/msg.go:475
    log.Infof("dataHash key: %v", key)

logs

time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest10 PRIMARY id 11750954]"
time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest3 PRIMARY id 11749486]"
time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest6 PRIMARY id 11751615]"
time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest3 PRIMARY id 11749635]"
time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest1 PRIMARY id 11748503]"
time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest10 PRIMARY id 11750955]"
time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest9 PRIMARY id 11750856]"
time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest1 PRIMARY id 11748504]"
time="2019-12-20T14:06:44+08:00" level=info msg="dataHash key: [test sbtest2 PRIMARY id 11750166]"
panic: runtime error: slice bounds out of range

goroutine 187 [running]:
github.com/OneOfOne/xxhash.(*XXHash64).Sum64(0xc0003a63c0, 0xc0003a63c0)
    /go/src/github.com/OneOfOne/xxhash/xxhash_unsafe.go:214 +0x30e
github.com/mitchellh/hashstructure.hashUpdateOrdered(0x331eaa0, 0xc0003a63c0, 0x7394306d06e88a10, 0x72f3286c31e6ce5a, 0x0)
    /go/src/github.com/mitchellh/hashstructure/hashstructure.go:345 +0x17d
github.com/mitchellh/hashstructure.(*walker).visit(0xc001aa3070, 0x29df3a0, 0xc002ae5de0, 0x97, 0x0, 0xc001b57e60, 0xc001aa3070, 0xc00090ce00)
    /go/src/github.com/mitchellh/hashstructure/hashstructure.go:312 +0xa25
github.com/mitchellh/hashstructure.Hash(0x29df3a0, 0xc002ae5de0, 0x48606e0, 0xc002ae5de0, 0xc001aa3178, 0x1)
    /go/src/github.com/mitchellh/hashstructure/hashstructure.go:89 +0x16b
github.com/moiot/gravity/pkg/inputs/mysqlstream.dataHash(0xc00114fff0, 0x4, 0xc001666020, 0x7, 0x2e60919, 0x7, 0xc00004f070, 0x1, 0x1, 0xc001b57dd0, ...)
    /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:476 +0x2ed
github.com/moiot/gravity/pkg/inputs/mysqlstream.dataHashForUKChange(0xc00114fff0, 0x4, 0xc001666020, 0x7, 0x2e60919, 0x7, 0xc00004f070, 0x1, 0x1, 0x0, ...)
    /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:435 +0x105
github.com/moiot/gravity/pkg/inputs/mysqlstream.GenerateDataHashes(0xc00114fff0, 0x4, 0xc001666020, 0x7, 0xc000eb2090, 0x0, 0xc001b57dd0, 0x2a3cc60, 0x2af7001, 0xc001e94490)
    /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:408 +0x3cb
github.com/moiot/gravity/pkg/inputs/mysqlstream.GenerateDMLDepHashes(0xc003019380, 0xc001670000, 0xc002419140, 0xc001b57dd0, 0xc001b57e00)
    /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:390 +0x7f
github.com/moiot/gravity/pkg/inputs/mysqlstream.NewInsertMsgs(0xc0002703f0, 0x28, 0xc00005afb0, 0x4, 0xc00005afb4, 0x7, 0x5dfc64ab, 0xbf77371d1eb9c52e, 0x2abe555fad, 0x4be6800, ...)
    /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/msg.go:92 +0x4c0
github.com/moiot/gravity/pkg/inputs/mysqlstream.(*BinlogTailer).Start.func1(0xc000758500, 0xc0002a6418, 0xc0007360c0, 0xc0004c23a0)
    /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/binlog_tailer.go:360 +0x20c0
created by github.com/moiot/gravity/pkg/inputs/mysqlstream.(*BinlogTailer).Start
    /go/src/github.com/moiot/gravity/pkg/inputs/mysqlstream/binlog_tailer.go:150 +0x35c

[Ryan-Git]

I can't reproduce this with the following test added to mysqlstream/msg_test.go. Could you have a try?

func TestXXHash(t *testing.T) {
	r := require.New(t)
	key := [][]interface{}{
		{"test", "sbtest10", "PRIMARY", "id", 11750954},
		{"test", "sbtest3", "PRIMARY", "id", 11749486},
		{"test", "sbtest6", "PRIMARY", "id", 11751615},
		{"test", "sbtest3", "PRIMARY", "id", 11749635},
		{"test", "sbtest1", "PRIMARY", "id", 11748503},
		{"test", "sbtest10", "PRIMARY", "id", 11750955},
		{"test", "sbtest9", "PRIMARY", "id", 11750856},
		{"test", "sbtest1", "PRIMARY", "id", 11748504},
		{"test", "sbtest2", "PRIMARY", "id", 11750166},
	}

	for _, k := range key {
		_, err := hashstructure.Hash(k, &hashOptions)
		r.NoError(err)
	}
}

[recall704]

I also can't reproduce with the same data, is other way to catch this bug ?

[Ryan-Git]

You can delete the hashOptions to use default hasher, hopefully it could work.
I've no idea for the root cause now.. what's your go version in production?