redis-faina: a query analysis tool for Redis
As we mentioned in our previous blog, we’re big fans of tools and techniques for introspecting our live traffic to see what exactly is going on. One tool we use frequently is PGFouine, a query traffic analyzer for PostgreSQL. We recently found that we also needed a similar tool for Redis, our swiss-army-knife list/set/etc storage.
We call it redis-faina and we’re making it open source so you can use it to monitor Redis as well (pgfouine = ‘pgweasel’ in French, redis-faina = ‘redisweasel’ in Italian as a tribute to Redis’ Italian heritage).
At its core, redis-faina uses the Redis MONITOR command, which echoes every single command (with arguments) sent to a Redis instance. It parses these entries, and aggregates stats on the most commonly-hit keys, the queries that took up the most amount of time, and the most common key prefixes as well. Using it, we’ve cut the number of requests on one of our systems from 23,000 requests per second to ~11,000, by identifying places where we could batch-fetch information or eliminate extraneous commands.
Usage is simple:
# reading from stdin redis-cli -p 6490 MONITOR | head -n <NUMBER OF LINES TO ANALYZE> | ./redis-faina.py # reading a file redis-cli -p 6490 MONITOR | head -n <...> > /tmp/outfile.txt ./redis-faina.py /tmp/outfile.txt
The output (anonymized below with ‘zzz’s) looks as follows:
Overall Stats ======================================== Lines Processed 117773 Commands/Sec 11483.44 Top Prefixes ======================================== friendlist 69945 followedbycounter 25419 followingcounter 10139 recentcomments 3276 queued 7 Top Keys ======================================== friendlist:zzz:1:2 534 followingcount:zzz 227 friendlist:zxz:1:2 167 friendlist:xzz:1:2 165 friendlist:yzz:1:2 160 friendlist:gzz:1:2 160 friendlist:zdz:1:2 160 friendlist:zpz:1:2 156 Top Commands ======================================== SISMEMBER 59545 HGET 27681 HINCRBY 9413 SMEMBERS 9254 MULTI 3520 EXEC 3520 LPUSH 1620 EXPIRE 1598 Command Time (microsecs) ======================================== Median 78.25 75% 105.0 90% 187.25 99% 411.0 Heaviest Commands (microsecs) ======================================== SISMEMBER 5331651.0 HGET 2618868.0 HINCRBY 961192.5 SMEMBERS 856817.5 MULTI 311339.5 SADD 54900.75 SREM 40771.25 EXEC 28678.5 Slowest Calls ======================================== 3490.75 "SMEMBERS" "friendlist:zzz:1:2" 2362.0 "SMEMBERS" "friendlist:xzz:1:3" 2061.0 "SMEMBERS" "friendlist:zpz:1:2" 1961.0 "SMEMBERS" "friendlist:yzz:1:2" 1947.5 "SMEMBERS" "friendlist:zpz:1:2" 1459.0 "SISMEMBER" "friendlist:hzz:1:2" "zzz" 1416.25 "SMEMBERS" "friendlist:zhz:1:2" 1389.75 "SISMEMBER" "friendlist:zzx:1:2" "zzz"
One caveat on timing: MONITOR only shows the time a command completed, not when it started. On a very busy Redis server (like most of ours), this is fine because there’s always a request waiting to execute, but if you’re at a lesser rate of requests, the time taken will not be accurate.
Also, MONITORing calls doesn’t come for free, so we mostly use to sample for a couple hundred thousand lines to get a representative sample.
Want to add more stats and improvements to redis-faina? Fork and send pull requests!
Want to work on analyzing, optimizing and designing systems that handle hundreds of thousands of requests per second across many, many machines? We’re hiring! Drop us a note and tell us a bit about yourself - we’re actively building out our dev & devops team.