Redis gets very slow

[Kashyap Mhaisekar]

Hi,

I have a redis instance that holds 1000 keys and there are 30 concurrent connections at any given point. Each of the 30 connections call 2 GETS.

1. First GET is a 16 character string

2. Second GET return 20KB of characters.

I find that as the concurrent connections grow, the GETS take close to 18 ms per GET.

The clients call REDIS using JEDIS pool and the Jedis sees the time of almost 500-1000 ms per call.

Questions

1. What is the standard time for a simple GET

2. Did anyone face issues with Jedis pool wrt latencies?

Thanks,

Kashyap

[Josiah Carlson]

How many Java threads are trying to perform these GET operations over how many pooled connections? Are you using any sort of pipelining? What is the network 'ping' time between your Java/Jedis clients and your Redis server? How fast is the network connection between your clients and servers?

I suspect you are running into a few issues:

1. You have a large number of Java threads attempting to use a small number of connections, and their requests are being delayed waiting for an available connection

2. Your network latency and/or bandwidth is limiting the throughput of an individual connection

3. You may not be using pipelining, which can result in these two GET calls to take 2 round trips instead of 1, doubling latency unnecessarily

Possible solutions given my suspicions:

* To address #3, you can use MGET instead of GET for a single call to get both of your keys, which will also help with #2, or use whatever pipelining mechanism is built into Jedis if you want to stick with two GET calls instead of MGET.

* To address #1 and #2 completely, you can disable connection pool limits.

 - Josiah

--
You received this message because you are subscribed to the Google Groups "Redis DB" group.
To unsubscribe from this group and stop receiving emails from it, send an email to redis-db+u...@googlegroups.com.
To post to this group, send email to redi...@googlegroups.com.
Visit this group at http://groups.google.com/group/redis-db.
For more options, visit https://groups.google.com/d/optout.

[Kashyap Mhaisekar]

Thanks Josiah,
Actually I see the GETs take close to 20ms on SLOWLOG COMMAND.

On your questions, the connection pool has 500 connections and  looks sufficient. My processing is from Storm bolts so each of 200 bolts accessing one connection of Redis.

Am concerned about Get taking 20ms for a 16 char string and 20kb object.

Thanks
Kashyap

[Josiah Carlson]

What does the INFO output from Redis say? Can you provide the first few lines of 'top' all the way to and including the line starting with 'Swap:'? How fast is the machine running Redis? Is the server running Redis running any other disk, network, RAM, or CPU intensive servers, services, or applications?

I know that you are concerned about the slow fetches of data. I'm trying to diagnose your issue via email by asking questions that should hopefully lead to an answer.

 - Josiah

[Kashyap Mhaisekar]

Josiah,

Thank you. Here goes -

Top:

top - 23:07:35 up 483 days,  6:49,  2 users,  load average: 0.03, 0.02, 0.00

Tasks: 171 total,   1 running, 170 sleeping,   0 stopped,   0 zombie

Cpu(s):  0.1%us,  0.1%sy,  0.0%ni, 99.8%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st

Mem:   7940528k total,  3815156k used,  4125372k free,   604792k buffers

Swap:  3907576k total,    11320k used,  3896256k free,  1226152k cached

And the Info -

127.0.0.1:12421> info

# Server

redis_version:2.8.19

redis_git_sha1:00000000

redis_git_dirty:0

redis_build_id:f3df8168ee1b2447

redis_mode:standalone

os:Linux 2.6.32-279.14.1.el6.x86_64 x86_64

arch_bits:64

multiplexing_api:epoll

gcc_version:4.4.6

process_id:5357

run_id:77f54d42c7869f03ddb9c1dcf79d7ee6bcb4b80b

tcp_port:12421

uptime_in_seconds:32130

uptime_in_days:0

hz:10

lru_clock:5426552

config_file:/appl/redis-2.8.19/conf/redis_12421.conf

# Clients

connected_clients:1

client_longest_output_list:0

client_biggest_input_buf:0

blocked_clients:0

# Memory

used_memory:26838656

used_memory_human:25.60M

used_memory_rss:28880896

used_memory_peak:32508936

used_memory_peak_human:31.00M

used_memory_lua:35840

mem_fragmentation_ratio:1.08

mem_allocator:jemalloc-3.6.0

# Persistence

loading:0

rdb_changes_since_last_save:3000

rdb_bgsave_in_progress:0

rdb_last_save_time:1431457861

rdb_last_bgsave_status:ok

rdb_last_bgsave_time_sec:0

rdb_current_bgsave_time_sec:-1

aof_enabled:0

aof_rewrite_in_progress:0

aof_rewrite_scheduled:0

aof_last_rewrite_time_sec:-1

aof_current_rewrite_time_sec:-1

aof_last_bgrewrite_status:ok

aof_last_write_status:ok

# Stats

total_connections_received:30337

total_commands_processed:564938

instantaneous_ops_per_sec:1

total_net_input_bytes:38659210

total_net_output_bytes:550839824

instantaneous_input_kbps:0.05

instantaneous_output_kbps:0.00

rejected_connections:0

sync_full:2

sync_partial_ok:0

sync_partial_err:1

expired_keys:0

evicted_keys:0

keyspace_hits:23139

keyspace_misses:330072

pubsub_channels:0

pubsub_patterns:0

latest_fork_usec:268

# Replication

role:master

connected_slaves:1

slave0:ip=10.2.8.28,port=21411,state=online,offset=22876794,lag=0

master_repl_offset:22876794

repl_backlog_active:1

repl_backlog_size:1048576

repl_backlog_first_byte_offset:21828219

repl_backlog_histlen:1048576

# CPU

used_cpu_sys:28.11

used_cpu_user:14.40

used_cpu_sys_children:0.01

used_cpu_user_children:0.00

# Keyspace

db6:keys=3000,expires=0,avg_ttl=0

Thank you!

Kashyap

[Kashyap Mhaisekar]

My bad, the redis gets are shown in microseconds... so slow queries is not an issue. What is an issue is the results coming through Jedis which takes 300ms. Are there any kernel level optimizations that can be done?

Regards,

Kashyap

[Josiah Carlson]

A 300ms per call latency is not a kernel issue.

The best thing that you can do right now to help us diagnose the issue is to provide the smallest amount of code that demonstrates the issue. After you do that, analysis will likely show that the issue lies in one or more of of: network bandwidth/latency (unrelated to kernel tuning), clients fighting over scarce connections, and/or a broken client/configuration/usage.

What have you done to diagnose the problem?

 - Josiah

[Greg Andrews]

Are all of the GET commands experiencing 300 millisecond durations?  Or just the slowest ones, and the average is less than 300 ms?

Your original message suggested that the slowness appears as the number of connections grows.  What number of connections marks the turning point from fast to slow?  Is it when you have more active threads in your app than connections in the pool to Redis?

  -Greg

On Thu, May 14, 2015 at 8:30 AM, Kashyap Mhaisekar <kash...@gmail.com> wrote:

[Kashyap Mhaisekar]

Greg,

I tuned the vm.overcommit, THP and TCP backlog and now the responses come back in like 8 ms on an average as against an average of 50 ms to 300 ms. Not sure what else to do to reduce this to under 3 ms as it is a GB ethernet and execution on REDIS is hardly 60 microseconds. The config  for connection pool is as follows.

config.setMaxActive(500);

config.setTestOnBorrow(true);

config.setTestOnReturn(true);

config.setMaxIdle(100);

Regards,

Kashyap