Order
This article mainly studies redis slowlog and latency monitor
slowlog
Redis introduced slowlog in version 2.2.12 to record commands that exceed the specified execution time. This execution time does not include IO operation time such as communication with the client, which is the actual command execution time. The main operations are as follows:
View the number of slowlog
127.0.0.1:6379> slowlog len
(integer) 1024
View slowlog execution time threshold
127.0.0.1:6379> config get slowlog-log-slower-than
1) "slowlog-log-slower-than"
2) "1000"
Set the slowlog execution time-consuming threshold.
127.0.0.1:6379> config set slowlog-log-slower-than 1000
OK
See the threshold for the number of slowlog saves.
127.0.0.1:6379> config get slowlog-max-len
1) "slowlog-max-len"
2) "1024"
Set the threshold for the number of slowlog saves.
127.0.0.1:6379> config set slowlog-max-len 1024
OK
Query slowlog
127.0.0.1:6379> slowlog get 1
1) 1) (integer) 76016
2) (integer) 1537250266
3) (integer) 48296
4) 1) "COMMAND"
The first line is the command id, the second line is timestamp, the third line is the execution time, and the fourth line is the command and parameters
Clear slowlog record
127.0.0.1:6379> slowlog reset
OK
latency monitor
Redis introduced latency monitoring in version 2.8.13, which mainly monitors latency spikes (Delay glitch
)。 It monitors based on the event mechanism. command event is the latency of monitoring command execution, fast-command event is the latency of monitoring commands with time complexity of O(1) and O(logN), and fork event is the latency of redis execution system call fork(2). The main operations are as follows:
Set up/open latency monitor
127.0.0.1:6379> config set latency-monitor-threshold 100
OK
Read latency monitor configuration
127.0.0.1:6379> config get latency-monitor-threshold
1) "latency-monitor-threshold"
2) "100"
Get the latest latency
127.0.0.1:6379> debug sleep 1
OK
(1.01s)
127.0.0.1:6379> debug sleep .25
OK
127.0.0.1:6379> latency latest
1) 1) "command"
2) (integer) 1537268070
3) (integer) 250
4) (integer) 1010
Returns the event name, timestamp of occurrence, latest delay (
Millisecond
), maximum delay (Millisecond
)
View the delay history of an event
127.0.0.1:6379> latency history command
1) 1) (integer) 1537268064
2) (integer) 1010
2) 1) (integer) 1537268070
2) (integer) 250
View event delay diagram
127.0.0.1:6379> latency reset command
(integer) 0
127.0.0.1:6379> debug sleep .1
OK
127.0.0.1:6379> debug sleep .2
OK
127.0.0.1:6379> debug sleep .3
OK
127.0.0.1:6379> debug sleep .4
OK
127.0.0.1:6379> debug sleep .5
OK
(0.50s)
127.0.0.1:6379> latency graph
(error) ERR syntax error
127.0.0.1:6379> latency graph command
command - high 500 ms, low 100 ms (all time high 500 ms)
--------------------------------------------------------------------------------
_#
_||
_|||
_||||
22117
4062s
ssss
Reset/Empty Event Data
127.0.0.1:6379> latency reset command
(integer) 1
127.0.0.1:6379> latency history command
(empty list or set)
127.0.0.1:6379> latency latest
(empty list or set)
Diagnostic advice
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: 6 latency spikes (average 257ms, mean deviation 142ms, period 3.83 sec). Worst all time event 500ms.
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.
Summary
- Redis’ slowlog was introduced in version 2.2.12 and latency monitor was introduced in version 2.8.13
- Slowlog only records the execution time of pure commands, excluding IO interaction with clients and fork of redis
- Latency spikes monitored by latency monitor have a wider scope, including not only command execution, but also the time-consuming operations such as fork(2) system call and key expiration.