Focused Topics in Redis Day 3 - #10

Troubleshooting Redis Latency

In this topic …

Latency, as understood in the Redis community, is broken down into three ways:

  1. command latency , is the amount of time it takes to execute a command. Some commands are fast and operate in O(1) while other commands have O(n) time complexity and are thereby a likely source of this type of latency.
  2. round-trip latency the time between when a client issues a command and then receives the response from the Redis server that can be caused by network congestion.
  3. client-latency if multiple clients attempt to connect to Redis at the same time, concurrency latency can be introduced as later clients may be waiting in queue for early client processes to complete.
  4. To help troubleshoot, Redis has a special mode for monitoring command latency that can be set in either redis.conf or from issuing a CONFIG SET for the latency-monitor-threshold directive.

    You can quickly run an latency check with redis-cli

    redis-cli --latency -h {host} -p {port}
          

Latency Monitoring

The Redis latency-monitor-threshold directive sets a limit in milliseconds that will log all or some of the commands and activity (called events) of the Redis instance that exceed that limit with a default of 0, meaning Redis does not automatically run latency monitoring but must be actively set.

First, we'll set our threshold to 100 milliseconds

127.0.0.1:6379> CONFIG SET latency-monitor-threshold 100
    

We’ll run a series of DEBUG SLEEP to demonstrate the various subcommands and functionality of Redis’s latency monitor.

127.0.0.1:6379> DEBUG SLEEP 1
127.0.0.1:6379> DEBUG SLEEP .25
127.0.0.1:6379> LATENCY LATEST
1) 1) "command"
   2) (integer) 1433877394
   3) (integer) 250
   4) (integer) 1000
      

The LATENCY LATEST the event name, the UNIX timestamp when the latency event occurred, the latest event latency in milliseconds, and the all-time maximum latency for this event.

The LATENCY HISTORY command and subcommand returns the latest 160 latency events that are being tracked

The LATENCY RESET either clear all latency events or just selected events by passing in one or more event names.

The LATENCY GRAPH command produces an ASCII-style graph of the logged latency events since the last LATENCY RESET command.


The LATENCY DOCTOR mode provides a rich set of human-readable (with flashes of HAL 9000 from Stanley Kubrick’s film 2001!) statistical data such as average time between latency spikes, median deviations of those spikes as well as human understandable analysis of the latency events and suggestions for reducing latency.

127.0.0.1:6379> latency doctor
Dave, I have observed latency spikes in this Redis instance. You don't mind talking about it, do you Dave?

1. command: 9 latency spikes (average 595ms, mean deviation 261ms, period 4.89 sec). Worst all time event 1044ms.

I have a few advices for you:

- Check your Slow Log to understand what are the commands you are running which are too slow to execute. Please check http://redis.io/commands/slowlog for more information.
- Deleting, expiring or evicting (because of maxmemory policy) large objects is a blocking operation. If you have very large objects that are often deleted, expired, or evicted, try to fragment those objects into multiple smaller objects.
127.0.0.1:6379>