Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Optimize aggregation buffer cleanup in CommandHandler #906

Closed
gavincook opened this issue Oct 30, 2018 · 7 comments
Closed

Optimize aggregation buffer cleanup in CommandHandler #906

gavincook opened this issue Oct 30, 2018 · 7 comments
Labels
type: feature A new feature
Milestone

Comments

@gavincook
Copy link
Contributor

gavincook commented Oct 30, 2018

When use pressure test to get data from redis, the redis data value is 16KB. It will cause the out of direct memory.
Saw the source code, I found:
Now the method decode in io.lettuce.core.protocol.CommandHandler will try to decode message received from redis server. When faced partial response message(most under BULK scene), will try to continue receive more and then decode more. While current buffer end with a complete message, it will discard the read bytes.
This behavior will keep read bytes always until input buffer end with a complete message. Under my pressure test sense, will always get partial message.

Reproduction setup

  1. first set a small direct memory to make it easy to reach the direct memory limit, like 50M with -XX:MaxDirectMemorySize=20m
  2. then set the logger level for io.lettuce.core.protocol to DEBUG
    Use below test code:
package io.lettuce.core.protocol;

import io.lettuce.core.RedisClient;
import io.lettuce.core.api.StatefulRedisConnection;
import io.lettuce.core.api.async.RedisAsyncCommands;
import java.util.concurrent.TimeUnit;

public class MemoryLeakTest {

    public static void main(String[] args) throws InterruptedException {
        RedisClient redisClient = RedisClient.create("redis://localhost:6379/0");
        StatefulRedisConnection<String, String> connection = redisClient.connect();
        RedisAsyncCommands<String, String> syncCommands = connection.async();

        syncCommands.set("key", "quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string,"
            + "quiet long string,quiet long string,quiet long string,quiet long string,quiet long string")
                    .await(5, TimeUnit.SECONDS);

        long startTime = System.currentTimeMillis();
        while (System.currentTimeMillis() - startTime <= 30_000) {
            syncCommands.get("key");
        }
        connection.close();
        redisClient.shutdown();
    }

}

Then the exception occur:

2018-10-31 10:40:51 [DEBUG] [lettuce-kqueueEventLoop-4-1] [channel=0x2ac75c7d, /127.0.0.1:64284 -> localhost/127.0.0.1:6379, chid=0x1] Unexpected exception during request: io.netty.util.internal.OutOfDirectMemoryError: failed to allocate 4194304 byte(s) of direct memory (used: 16845793, max: 20971520) (CommandHandler:216)

Environment

  1. redis : 4.0.11
  2. lettuce : 5.1.2-RELEASE
@gavincook
Copy link
Contributor Author

gavincook commented Oct 30, 2018

When decode failure, means end with a partial message. Now will just return to continue receive more.
The code:

 if (!decode(ctx, buffer, command)) {
     return;
 }

We should discard the read bytes when end with a partial message.

 if (!decode(ctx, buffer, command)) {
      if (buffer.refCnt() != 0) {
           buffer.discardReadBytes();
      }
     return;
 }

Maybe we don't need discard read bytes each time when end with a partial message. We can optimize some, like :

  1. monitor the buffer usage , when 1/3 left or less than a fixed size free, do discard
  2. when face out of memory, try to do discard

@mp911de
Copy link
Collaborator

mp911de commented Nov 6, 2018

Thanks for the report. We had early discardReadBytes in CommandHandler (see #725). It's not exactly what you proposed, but touches a similar idea.

Discarding copies bytes around which can have a performance impact in terms of CPU time. This is a balance between memory cost and CPU cost. Right now, we optimize for CPU.

The approach of free percentage seems quite appealing to me. Do you want to give it a spin by submitting a PR that introduces conditional discard after decoding a command?

@mp911de
Copy link
Collaborator

mp911de commented Nov 6, 2018

Update: That's not exactly a memory leak. A leak causes non-reclaimable memory. This one is rather an optimization to memory usage.

@gavincook
Copy link
Contributor Author

Sure, Let me try

@gavincook
Copy link
Contributor Author

Here i pushed a pr on 916 , providing a buffer usage ratio to optimize buffer memory usage.

@mp911de mp911de changed the title memory leak in CommandHandler Optimize aggregation buffer cleanup in CommandHandler Nov 13, 2018
@mp911de mp911de added this to the Backlog milestone Nov 13, 2018
@mp911de
Copy link
Collaborator

mp911de commented Nov 13, 2018

I adjusted the ticket title to reflect the actual purpose.

gavincook added a commit to gavincook/lettuce-core that referenced this issue Nov 20, 2018
gavincook added a commit to gavincook/lettuce-core that referenced this issue Nov 20, 2018
gavincook added a commit to gavincook/lettuce-core that referenced this issue Nov 20, 2018
gavincook added a commit to gavincook/lettuce-core that referenced this issue Nov 21, 2018
@mp911de mp911de modified the milestones: Backlog, 5.2.0 Nov 23, 2018
mp911de pushed a commit that referenced this issue Nov 23, 2018
…sageRatio #906

We now allow configuration of when ByteBuf.discardReadBytes() gets called. Memory freeing can be useful during decoding of large responses instead of waiting until decoding is finished.

Original pull request: #916
mp911de added a commit that referenced this issue Nov 23, 2018
Improve documentation. Add author tags. Precompute expected-to-discard buffer usage ratio instead of computing it on each discard. Add override to ClusterClientOptions Builder. Add and fix tests. Reformat code.

Original pull request: #916
@mp911de
Copy link
Collaborator

mp911de commented Nov 23, 2018

PR #916 is merged now. Thanks a lot.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: feature A new feature
Projects
None yet
Development

No branches or pull requests

2 participants