ERR Corruption: Corrupted compressed block contents: Snappy

[corningsun]

Search before asking

• I had searched in the issues and found no similar issues.

Version

2.1

Minimal reproduce step

1 build kvrocks with branch 2.1

2 start kvrocks cluster (One Master)

3 set cluster nodes

CLUSTERX SETNODEID kvrockskvrockskvrockskvrocksstgnodeid001
CLUSTERX SETNODES "kvrockskvrockskvrockskvrocksstgnodeid001 127.0.0.1 6666 master - 0-16383" 1

4 put random key and value to redis

eg: use jedis client。

I have test other ways like RedisShake and got the same error.

package com.corning.kvrocks;

import org.apache.commons.lang3.RandomStringUtils;
import redis.clients.jedis.HostAndPort;
import redis.clients.jedis.JedisCluster;

import java.util.HashSet;
import java.util.Set;
import java.util.concurrent.atomic.AtomicInteger;

public class KvrocksTest {

    private static final AtomicInteger threadNum = new AtomicInteger(0);

    public static void main(String[] args) {
        int keyNum = Integer.parseInt(args[0]);
        System.out.println("keyNum=" + keyNum);

        int thread = args.length == 1 ? 1 : Integer.parseInt(args[1]);
        System.out.println("thread=" + thread);

        for (int i = 0; i < thread; i++) {
            new Thread(() -> startInsert(keyNum / thread)).start();
        }
    }

    private static void startInsert(int keyNum) {
        final int threadId = threadNum.getAndIncrement();
        System.out.printf("thread-%s: insertStart, keyNum=%s\n", threadId, keyNum);

        String pwd = "pwd";
        String host = "127.0.0.1";
        int port = 6666;
        long seconds = 60 * 60 * 24;

        Set<HostAndPort> nodes = new HashSet<>();
        nodes.add(new HostAndPort(host, port));

        try (JedisCluster cluster = new JedisCluster(nodes, null, pwd)) {
            for (int i = 0; i < keyNum; i++) {
                String key = "LOCAL_" + RandomStringUtils.randomAlphanumeric(1, 50);
                String value = RandomStringUtils.randomAlphanumeric(1, 100);
                cluster.setex(key, seconds, value);
            }
        }
        System.out.printf("thread-%s: insertEnd, keyNum=%s\n", threadId, keyNum);
    }

}

nohup java -jar kvorcks-test-1.0-SNAPSHOT.jar 10000000 10 > test.log 2>&1 &

What did you expect to see?

put all 10,000,000 random key/value to redis success

What did you see instead?

run well at first, bu after set about 4,000,000 keys, then set any key to redis will got ERROR

(error) ERR Corruption: Corrupted compressed block contents: Snappy

• log of redis-cli

redis-cli -h 127.0.0.1 -p 6666
127.0.0.1:6666> get a
"cTesZxX72jU1KkUoXCOejE5OKL6lTX0xXxK74ML3BTpahXzB3JDjr4I7KSrdIqz"
127.0.0.1:6666 set a 1
(error) ERR Corruption: Corrupted compressed block contents: Snappy
127.0.0.1:6666> set b 1
(error) ERR Corruption: Corrupted compressed block contents: Snappy
127.0.0.1:6666> get b
"WQz33uQAaMXhDMaNfyb7yk4ka0UtXO4DLqiR3oci0jnIQYCWxFXDOjLSfn2ynDDgabioA9mWJkOpuGgkxG"
127.0.0.1:6666> ttl b
(integer) 83826

• log of kvrocks.INFO file

I20220823 16:56:35.059758  3087 event_listener.cc:145] [event_listener/table_file_created] column family: metadata, file path: /opt/kvrocks/incubator-kvrocks/data/db/000020.sst, file size: 88686084, job id: 4, reason: flush, status: OK
I20220823 16:56:35.066828  3087 event_listener.cc:93] [event_listener/flush_completed] column family: metadata, thread_id: 140259820037888, job_id: 4, file: /opt/kvrocks/incubator-kvrocks/data/db/000020.sst, reason: 6, is_write_slowdown: no, is_write_stall: no, largest seqno: 1937914, smallest seqno: 974572
I20220823 16:59:47.759503  3090 event_listener.cc:85] [event_listener/flush_begin] column family: metadata, thread_id: 140259776001792, job_id: 5, reason: 6
I20220823 16:59:48.534060  3090 event_listener.cc:145] [event_listener/table_file_created] column family: metadata, file path: /opt/kvrocks/incubator-kvrocks/data/db/000023.sst, file size: 85550996, job id: 5, reason: flush, status: OK
I20220823 16:59:48.541939  3090 event_listener.cc:93] [event_listener/flush_completed] column family: metadata, thread_id: 140259776001792, job_id: 5, file: /opt/kvrocks/incubator-kvrocks/data/db/000023.sst, reason: 6, is_write_slowdown: no, is_write_stall: no, largest seqno: 2866819, smallest seqno: 1937915
I20220823 17:02:58.819249  3088 event_listener.cc:85] [event_listener/flush_begin] column family: metadata, thread_id: 140259805361920, job_id: 6, reason: 6
I20220823 17:02:59.652449  3088 event_listener.cc:145] [event_listener/table_file_created] column family: metadata, file path: /opt/kvrocks/incubator-kvrocks/data/db/000026.sst, file size: 84559171, job id: 6, reason: flush, status: OK
I20220823 17:02:59.666702  3088 event_listener.cc:93] [event_listener/flush_completed] column family: metadata, thread_id: 140259805361920, job_id: 6, file: /opt/kvrocks/incubator-kvrocks/data/db/000026.sst, reason: 6, is_write_slowdown: no, is_write_stall: no, largest seqno: 3785962, smallest seqno: 2866820
I20220823 17:03:01.341382  3083 event_listener.cc:145] [event_listener/table_file_created] column family: metadata, file path: /opt/kvrocks/incubator-kvrocks/data/db/000027.sst, file size: 136316402, job id: 7, reason: compaction, status: OK
I20220823 17:03:03.065637  3083 event_listener.cc:145] [event_listener/table_file_created] column family: metadata, file path: /opt/kvrocks/incubator-kvrocks/data/db/000028.sst, file size: 136303910, job id: 7, reason: compaction, status: OK
I20220823 17:03:04.008123  3083 event_listener.cc:145] [event_listener/table_file_created] column family: metadata, file path: /opt/kvrocks/incubator-kvrocks/data/db/000029.sst, file size: 72948978, job id: 7, reason: compaction, status: OK
I20220823 17:03:04.030848  3083 event_listener.cc:71] [event_listener/compaction_completed] column family: metadata, compaction reason: 1, output compression type: no, base input level(files): 0(4), output level(files): 1(3), input bytes: 348430487, output bytes:345569290, is_manual_compaction:no, elapsed(micro): 4341217
I20220823 17:03:04.047273  3083 event_listener.cc:132] [event_listener/table_file_deleted] db: /opt/kvrocks/incubator-kvrocks/data/db, sst file: /opt/kvrocks/incubator-kvrocks/data/db/000026.sst, status: OK
I20220823 17:03:04.063731  3083 event_listener.cc:132] [event_listener/table_file_deleted] db: /opt/kvrocks/incubator-kvrocks/data/db, sst file: /opt/kvrocks/incubator-kvrocks/data/db/000023.sst, status: OK
I20220823 17:03:04.080839  3083 event_listener.cc:132] [event_listener/table_file_deleted] db: /opt/kvrocks/incubator-kvrocks/data/db, sst file: /opt/kvrocks/incubator-kvrocks/data/db/000020.sst, status: OK
I20220823 17:03:04.092478  3083 event_listener.cc:132] [event_listener/table_file_deleted] db: /opt/kvrocks/incubator-kvrocks/data/db, sst file: /opt/kvrocks/incubator-kvrocks/data/db/000017.sst, status: OK
I20220823 17:03:06.037737  3083 event_listener.cc:145] [event_listener/table_file_created] column family: metadata, file path: /opt/kvrocks/incubator-kvrocks/data/db/000030.sst, file size: 136221198, job id: 8, reason: compaction, status: OK
I20220823 17:03:06.041982  3083 event_listener.cc:71] [event_listener/compaction_completed] column family: metadata, compaction reason: 2, output compression type: snappy, base input level(files): 1(1), output level(files): 2(0), input bytes: 136316402, output bytes:136221198, is_manual_compaction:no, elapsed(micro): 1945242
E20220823 17:03:06.042018  3083 event_listener.cc:127] [event_listener/background_error] reason: compact, bg_error: Corruption: Corrupted compressed block contents: Snappy
I20220823 17:03:07.067961  3083 event_listener.cc:132] [event_listener/table_file_deleted] db: /opt/kvrocks/incubator-kvrocks/data/db, sst file: /opt/kvrocks/incubator-kvrocks/data/db/000030.sst, status: OK

Anything Else?

• server info

CentOS Linux release 7.9.2009 (Core)
Linux version 3.10.0-1127.19.1.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-39) (GCC) ) #1 SMP Tue Aug 25 17:23:54 UTC 2020

Are you willing to submit a PR?

• I'm willing to submit a PR!

[git-hulk]

@corningsun Thanks for your feedback.

This issue looks like the same with #607, you can have a try at installing snappy. But I think it should a bug even it works after installing the snappy since we expected to static link the snappy.

[corningsun]

It's not work for me, snappy already installed

[root@VM-24-10-centos ~]# yum install snappy
Loaded plugins: fastestmirror, langpacks
Repository epel is listed more than once in the configuration
Loading mirror speeds from cached hostfile
Package snappy-1.1.0-3.el7.x86_64 already installed and latest version
Nothing to do

[git-hulk]

@corningsun Can you paste the output of ldd ./kvrocks? I want to check whether Kvrocks dynamic linked the snappy library.

And output like below was expected:

root@39c518410166:/kvrocks# ldd bin/kvrocks
	linux-vdso.so.1 (0x00007ffdd551d000)
	libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007f9fbd8a6000)
	libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007f9fbd883000)
	libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007f9fbd734000)
	libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f9fbd542000)
	/lib64/ld-linux-x86-64.so.2 (0x00007f9fbe4f7000)

[corningsun]

[root@VM-24-10-centos build]# ldd ./kvrocks
linux-vdso.so.1 => (0x00007ffc679a3000)
librt.so.1 => /lib64/librt.so.1 (0x00007f5fe0c3d000)
libpthread.so.0 => /lib64/libpthread.so.0 (0x00007f5fe0a21000)
libunwind.so.8 => /lib64/libunwind.so.8 (0x00007f5fe0807000)
libm.so.6 => /lib64/libm.so.6 (0x00007f5fe0505000)
libc.so.6 => /lib64/libc.so.6 (0x00007f5fe0137000)
/lib64/ld-linux-x86-64.so.2 (0x00007f5fe0e45000)
libgcc_s.so.1 => /lib64/libgcc_s.so.1 (0x00007f5fdff21000)

[git-hulk]

hmmmm, I don't know why it happens and need to reproduce on my side later. You can try to uninstall the snappy library and rebuild the source from scratch again.

[git-hulk]

@corningsun I can reproduce it on CentOS 7 but need more time to investigate the root cause. You can workaround by switching rocksdb.compression to lz4 in kvrocks.conf, I tried the lz4 and it works well.

BTW: @PragmaTwice I'm not sure whether current snappy library has any difference with old cmake way, can help me out if you have any clues.

[PragmaTwice]

Currently no, but I will try to reproduce it and see what happened.

[git-hulk]

Thanks @PragmaTwice, I used the redis-benchmark -p 6666 -t set -d 102400 -r 100000000 -n 10000000 command to reproduce this on CentOS7. It happens after compacting into level 2 which will use the snappy compression, to fast reproduce that we can remove the if condition https://github.com/apache/incubator-kvrocks/blob/unstable/src/storage.cc#L144

[corningsun]

@corningsun I can reproduce it on CentOS 7 but need more time to investigate the root cause. You can workaround by switching rocksdb.compression to lz4 in kvrocks.conf, I tried the lz4 and it works well.

BTW: @PragmaTwice I'm not sure whether current snappy library has any difference with old cmake way, can help me out if you have any clues.

rocksdb.compression lz4 is OK for me, Thanks for the answer.

[git-hulk]

@corningsun I found it's caused by the newer version(v1.1.9) snappy didn't work right with RocksDB. I have submitted #790 to fix it but didn't have time to study and investigate what happens in the snappy library. You can also help to try and confirm this fix if you don't mind.

cc @PragmaTwice

[corningsun]

@corningsun I found it's caused by the newer version(v1.1.9) snappy didn't work right with RocksDB. I have submitted #790 to fix it but didn't have time to study and investigate what happens in the snappy library. You can also help to try and confirm this fix if you don't mind.

cc @PragmaTwice

@git-hulk snappy v1.1.7 works fine.

With branch revert-snappy-to-old-version, I have had insert 52 Mil keys to kvrocks, everything is OK.

git clone git@github.com:git-hulk/incubator-kvrocks.git -b revert-snappy-to-old-version

[git-hulk]

@corningsun Many thanks to your kind check.