Lettuce/Lobby

Chat room for the Lettuce Redis driver project

Lazar Bulić

@pendula95

So any connection issue is not handled by this option and I think it should

Lazar Bulić

@pendula95

Is there any reason this only affects protocol connection

and not Socket connection

Mark Paluch

@mp911de

Commands do timeout if they aren’t completed within their timeout. It does not matter whether a node was not reachable or the processing is just slow.

Re reconnect failures: some setups mess with hostnames or port forwarding, therefore all IO exceptions (connection rejected, unknown host, others) cause another reconnect attempt.

If the Redis service gets restarted within a couple of seconds there’s no point in cancelling all queued commands.

Lazar Bulić

@pendula95

ok does timeout work on async connection?

Lazar Bulić

@pendula95

ok I removed reloadPartitions() as it was messing up with the event loop

What are my options for triggering topology update/reparation manually in non blocking way

Is it also possible to make connection.reactive() be really reactive/async as it keeps blocking by eventloop

Lazar Bulić

@pendula95

the* eventloop

Mark Paluch

@mp911de

Timeouts (when using global timeouts via ClientOptions) are applied to async and reactive commands as well.

Topology refresh would require a rewrite to non-blocking. There are a couple of timeout-gated synchronization stages and I could need some help to rewrite it.

Lazar Bulić

@pendula95

Also is there a difference between period refresh and adaptive refresh behaviour?Because when triggered in failover by adaptive trigger I see my event loop get blocked slightly but I can't see period refresh blocking by event loop when set.

Also why is this action so slow, CLUSTER NODES should just read state from file?

Lazar Bulić

@pendula95

I guess the slow time has to do with this antirez/redis#5574

Mark Paluch

@mp911de

The I/O event loop should not be affected. Background topology refresh runs on a separate event executor

Lazar Bulić

@pendula95

https://gist.github.com/pendula95/b3b9934482fbe72e31615261fe84771e

Notice the timestamps

....
16:27:03.534 [lettuce-eventExecutorLoop-1-7] WARN c.i.lettuce.RetryWithDelay - Retry = 10 time for error = Command timed out after 1 second(s)
16:27:04.535 [lettuce-eventExecutorLoop-1-7] WARN c.i.lettuce.RetryWithDelay - Retry = 11 time for error = Command timed out after 1 second(s)
16:27:05.536 [lettuce-eventExecutorLoop-1-8] WARN c.i.lettuce.RetryWithDelay - Retry = 12 time for error = Command timed out after 1 second(s)

And than this

16:27:12.795 [lettuce-nioEventLoop-4-5] WARN i.l.c.protocol.ConnectionWatchdog - Cannot reconnect: io.netty.channel.ConnectTimeoutException: connection timed out: /172.20.0.3:6379

Why there is 7 sec delay

looks like event loop block to me

...

16:27:12.848 [lettuce-eventExecutorLoop-1-1] WARN c.i.lettuce.RetryWithDelay - Retry = 13 time for error = Command timed out after 1 second(s)
16:27:12.853 [lettuce-nioEventLoop-4-4] INFO com.ipification.lettuce.LettuceConn - Count = 128

Mark Paluch

@mp911de

ConnectionWatchdog reduces internally logging to print error logs only once every 5 seconds

See https://github.com/lettuce-io/lettuce-core/blob/master/src/main/java/io/lettuce/core/protocol/ConnectionWatchdog.java#L276-L282

By default, reconnect uses a binary exponential delay, see https://github.com/lettuce-io/lettuce-core/blob/master/src/test/java/io/lettuce/core/resource/ExponentialDelayUnitTests.java#L69-L80 for the actual values.

Lazar Bulić

@pendula95

I don't get how links you provided are connected to the issue. Retry = * time for error = Command timed out after 1 second(s) are my logs when I try to retry same command when it fails (in this case timeouts as failover is in progress). I retry instantly when command timeouts and you can see that timestamps for retry prove that - 16:27:03.534 -> 16:27:04.535 -> 16:27:05.536

But than retry for some reason stops and next message that is printed is 16:27:12.795 [lettuce-nioEventLoop-4-5] WARN i.l.c.protocol.ConnectionWatchdog - Cannot reconnect: io.netty.channel.ConnectTimeoutException: connection timed out: /172.20.0.3:6379. This means something blocked my retry for 7 sec.

So I guess something blocked the eventloop or timeout is not working as my retry for some reason got delayed.

Mark Paluch

@mp911de

You were specifically asking for the 7 second delay of ConnectionWatchDog and the explanation above is why you see a gap in reconnect messages.

Lazar Bulić

@pendula95

So to sum it up, I see this as bug

Logging mechanism in watchdog has nothing to with my app logger messages not being logged. I come to a conclusion that it might be indirect eventloop blocking or for some reason timeout is not thrown correctly when reconnect/rebalance process in action. Am I right?

Lazar Bulić

@pendula95

this is my class > WARN c.i.lettuce.RetryWithDelay

kjham

@kjham

hi !
Is there a redis client that works with jdk 1.4?

James Howe

@OrangeDog

Given Redis was first released five years after it became obsolete, I'm going to guess a hard no

But you can try forking the source of one and stripping out all newer APIs and generics. ~~If there's one that doesn't use NIO that'd be better to start from.~~ Java 1.4 has NIO at least.

kjham

@kjham

Thank you for your kind answers.
What does 'NIO' mean?

NIO: It means New Input / Output ...

If I removed all of the new APIs, it would be possible.
It will not be easy.

James Howe

@OrangeDog

no, NIO means Non-blocking Input/Output

kjham

@kjham

Oh, yes. Thank you.

I need to create a plugin jar in java 1.4. I'm in trouble. Your answer was helpful.

max-grigoriev

@max-grigoriev

hi guys,

Does anyone know why there's so strange behavior of 5.1.8.RELEASE Lettuce when I use reactive commands:

        getPersonsWhoBlocked(personUid).subscribe();
        getPersonsWhoBlocked(personUid).subscribe();
        getPersonsWhoBlocked(personUid).subscribe();
        getPersonsWhoBlocked(personUid).subscribe();
        getPersonsWhoBlocked(personUid).subscribe();
        getPersonsWhoBlocked(personUid).subscribe();
        getPersonsWhoBlocked(personUid).subscribe();

and I see that always first command blocks the remaining one.

public Flux<String> getPersonsWhoBlocked(@NonNull String personUid) {
        final AtomicLong start = new AtomicLong(System.currentTimeMillis());
        return Mono.just(personUid)
                .doOnNext(uid -> log.info("Start ....."))
                .flatMapMany(uid -> commands.smembers(whoBlockPrefix + uid)
                        .defaultIfEmpty("12345")
                        .doOnNext(s -> log.info("End {} .....", (System.currentTimeMillis()- start.get())))
                );
}

Logs:

18:08:14.681 INFO  dw-77 -  Start .....
18:08:14.681 INFO  dw-77 -  Start .....
18:08:14.682 INFO  dw-77 -  Start .....
18:08:14.682 INFO  dw-77 -  Start .....
18:08:14.682 INFO  dw-77 -  Start .....
18:08:14.685 INFO  dw-77 - Start .....
18:08:14.686 INFO  dw-77 -  Start .....
18:08:14.883 INFO  lettuce-kqueueEventLoop-4-4  - End 202 .....
18:08:14.883 INFO  lettuce-kqueueEventLoop-4-4  - Reduce.....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - End 399 .....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - Reduce.....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - End 398 .....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - Reduce.....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - End 398 .....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - Reduce.....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - End 398 .....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - Reduce.....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - End 395 .....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - Reduce.....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - End 394 .....
18:08:15.080 INFO  lettuce-kqueueEventLoop-4-4  - Reduce.....

As you can see the first command takes 200 ms and all others are waiting for it. Then remaining commands start running in non blocking mode.

Where communities thrive

People

Repo info

Activity