redisson: Missing PubSub messages when using connection ping

### Expected behavior setPingConnectionInterval should send periodic ping messages and keep channels alive, but this must not affect any other type of messages on channels.

Actual behavior

When using setPingConnectionInterval some messages will not be delivered to listeners after being published. I have a test code which can reliably reproduce this issue:

import org.redisson.Redisson;
import org.redisson.api.RTopic;
import org.redisson.api.RedissonClient;
import org.redisson.codec.SerializationCodec;
import org.redisson.config.Config;
import org.redisson.config.SubscriptionMode;

import java.util.UUID;
import java.util.concurrent.ConcurrentSkipListSet;

public class PlainPubSubTest {

    public static void main(String[] args) throws InterruptedException {
        ConcurrentSkipListSet<String> sentItems = new ConcurrentSkipListSet<>();
        ConcurrentSkipListSet<String> receivedItems = new ConcurrentSkipListSet<>();

        System.out.println("Staring test");

        RedissonClient redissonClient = redissonClient(configSentinel());

        RTopic<String> eventsTopic = redissonClient.getTopic("eventsTopic");
        eventsTopic.addListener((channel, msg) -> receivedItems.add(msg));

        System.out.println("Starting sending loop");
        for(int i = 0; i<1000; i++){
            final String message = UUID.randomUUID().toString();
            eventsTopic.publish(message);
            sentItems.add(message);
            Thread.sleep(10);
        }

        System.out.println("Sent: " + sentItems.size() + ", got: " + receivedItems.size());
        Thread.sleep(1000);
        System.out.println("Sent: " + sentItems.size() + ", got: " + receivedItems.size());
    }

    private static RedissonClient redissonClient(Config config){
        return Redisson.create(config);
    }

    private static Config configSentinel(){
        Config config = new Config();
        config.setCodec(new SerializationCodec());
        String password = "*****************";
        String masterName = "my-master-name";
        String[] sentinelAddresses = new String[]{"redis://localhost:26001", "redis://localhost:26002", "redis://localhost:26003"};
        Integer connectionTimeout = 10000;
        int pingTimeout = 5000;
        int reconnectionTimeout = 5000;
        int connectionPoolSize = 10;
        int connectionPoolMinSize = 10;
        int connectionPingInterval = 50; //Changing to 0 eliminates issue
        config.useSentinelServers()
                .setPassword(password)
                .setMasterName(masterName)
                .addSentinelAddress(sentinelAddresses)
                .setConnectTimeout(connectionTimeout)
                .setPingTimeout(pingTimeout)
                .setPingConnectionInterval(connectionPingInterval)
                .setSubscriptionMode(SubscriptionMode.MASTER)
                .setFailedSlaveReconnectionInterval(reconnectionTimeout)
                .setMasterConnectionMinimumIdleSize(connectionPoolMinSize)
                .setMasterConnectionPoolSize(connectionPoolSize);
        return config;
    }
}

Output of this code will produce varying results each time, but it will never get all sent messages, like this:

Staring test
Starting sending loop
Sent: 1000, got: 640
Sent: 1000, got: 640

However if connectionPingInterval is set to 0 (disabled) issue is completely eliminated, like this:

Staring test
Starting sending loop
Sent: 1000, got: 1000
Sent: 1000, got: 1000

Redis version

redis_version:4.0.6
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:f1060815dd32471a
redis_mode:standalone
os:Linux 3.10.0-514.26.1.el7.x86_64 x86_64

Redisson version

3.7.2

Redisson configuration

Visible in test case

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Comments: 22 (9 by maintainers)

Commits related to this issue

Most upvoted comments

Also tested on clean linux (debian 9, 4.9.0-8-amd64, openjdk 11, redis 4.0.11, redission 3.0.0 branch). Not at every run, but very often gives the same: https://gist.github.com/valodzka/da427f73b2c6437460bc4be3b527ac45/revisions

Same issue, not fixed.

I’m unable to reproduce it with current test

Thats weird. I created special project https://github.com/valodzka/redisson-issue-1497. Easily reproducible (like 80% times) for me at commit 7b20c0d9a55762ea86d1dd6505afbccd20d56079 with java 11 and java 8, redis 4 and redis 5 (mac os 10.13.6). Log example https://gist.github.com/valodzka/da427f73b2c6437460bc4be3b527ac45.

Same issue as of redisson 3.9.0. Same reproducer. Works well with pingConnectionInterval(0), fails with pingConnectionInterval(50). A bit different exception:

java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 1
at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:64)
at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckIndex(Preconditions.java:70)
at java.base/jdk.internal.util.Preconditions.checkIndex(Preconditions.java:248)
at java.base/java.util.Objects.checkIndex(Objects.java:372)
at java.base/java.util.ArrayList.get(ArrayList.java:458)
at org.redisson.client.handler.State.getLastLevel(State.java:56)
at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:359)
at org.redisson.client.handler.CommandDecoder.decodeFromCheckpoint(CommandDecoder.java:199)
at org.redisson.client.handler.CommandPubSubDecoder.decodeCommand(CommandPubSubDecoder.java:90)
at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:108)
at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:502)
at io.netty.handler.codec.ReplayingDecoder.callDecode(ReplayingDecoder.java:366)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:278)

This issue is reproducable in 2 of 5 test executions. I have fixed it.

Fixed! Thanks for report