Slow queries not showing up in SLOWLOG

[fbjork]

I have a Redis instance on EC2 that we run MGET commands with 25-50 keys passed in. At random we see a spike of commands that take longer than 200ms to run which we log in our app. However, those slow queries don't show up in the SLOWLOG GET list.

Connections are persistent and I'm not seeing any connections be dropped or opened during the time of slow latency. I'm assuming this is due to poor network conditions, but I'd like to here what others have to say.

This is a Sinatra app using the redis-rb gem. Any ideas how to troubleshoot this?

[Yanhong Wu]

If you have snapshot on your instance, redis server can have no  response  for a short time. If you experienced it from time to time, that must be snapshot. By default it's five minutes. 

--
You received this message because you are subscribed to the Google Groups "Redis DB" group.
To view this discussion on the web visit https://groups.google.com/d/msg/redis-db/-/ZroowM2NmWcJ.
To post to this group, send email to redi...@googlegroups.com.
To unsubscribe from this group, send email to redis-db+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/redis-db?hl=en.

--
吴焱红 Samuel

新浪微博: 扇贝网
人人：一起背单词
博客：扇贝网(一起背单词)

[fbjork]

Snapshotting is disabled on this instance. What else could it be?

[Yanhong Wu]

Check IO of the instance when the latency happened ? 

To view this discussion on the web visit https://groups.google.com/d/msg/redis-db/-/z-D-z6tqRBUJ.

To post to this group, send email to redi...@googlegroups.com.
To unsubscribe from this group, send email to redis-db+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/redis-db?hl=en.

[Greg Andrews]

What does Redis log to the slow log?  The comment lines in the 2.4.17 redis.conf file say:

# The Redis Slow Log is a system to log queries that exceeded a specified
# execution time. The execution time does not include the I/O operations
# like talking with the client, sending the reply and so forth,
# but just the time needed to actually execute the command (this is the only
# stage of command execution where the thread is blocked and can not serve
# other requests in the meantime).

So the entries in the slow log are commands which took Redis a long time to execute.  If it took a long time to receive the command from the client, or to send the response back to the client, Redis will not log the command.

So you have a Ruby client that says it took a long time between sending the command and receiving the reply, but the server says it didn't take a long time to execute the command.  The first cause that comes to mind and matches those symptoms is network latency.  The second that comes to mind is the Ruby gem and/or run-time environment.  (I'm not pointing fingers at Ruby or redis-rb, just listing the potential sources of latency)

Myself, I'd cut to the chase and capture the network traffic with tcpdump on both a client machine and the Redis server machine.  When the client reports a slow MGET, find the packets in the two tcpdump capture files and see where the delay happens in the round-trip path.

  -Greg

--