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 isPGFouine, 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 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 and devops team.