t/aio-ring: add cache hit statistics
authorJens Axboe <axboe@kernel.dk>
Fri, 14 Dec 2018 17:54:01 +0000 (10:54 -0700)
committerJens Axboe <axboe@kernel.dk>
Fri, 14 Dec 2018 17:54:01 +0000 (10:54 -0700)
commit305c06ce47798d7b93d925819975b1fa2284759f
treed483f5cf9501580be0dcd93fd46f4514d3a6216e
parent96563db9995c5cebdce526f2bf97923153d4456b
t/aio-ring: add cache hit statistics

Pretty nifty to run it on a drive that will eventually end up being
fully cached, and watch the hit rates climb:

sudo taskset -c 0 t/aio-ring /dev/sde3
polled=0, fixedbufs=1, buffered=1
  QD=32, sq_ring=33, cq_ring=66
submitter=4269
IOPS=477, IOS/call=1/0, inflight=32 (head=50 tail=50), Cachehit=0.00%
IOPS=447, IOS/call=1/1, inflight=32 (head=35 tail=35), Cachehit=0.00%
IOPS=419, IOS/call=1/1, inflight=32 (head=58 tail=58), Cachehit=0.00%
[...]
IOPS=483, IOS/call=1/1, inflight=32 (head=63 tail=63), Cachehit=5.80%
IOPS=452, IOS/call=1/1, inflight=32 (head=53 tail=53), Cachehit=4.65%
IOPS=459, IOS/call=1/1, inflight=32 (head=50 tail=50), Cachehit=5.45%
[...]
IOPS=484, IOS/call=1/1, inflight=32 (head=22 tail=22), Cachehit=11.16%
IOPS=494, IOS/call=1/1, inflight=32 (head=54 tail=54), Cachehit=11.34%
IOPS=508, IOS/call=1/1, inflight=32 (head=34 tail=34), Cachehit=12.99%
[...]
IOPS=606, IOS/call=1/1, inflight=32 (head=18 tail=18), Cachehit=26.07%
IOPS=573, IOS/call=1/1, inflight=32 (head=63 tail=63), Cachehit=26.70%
IOPS=561, IOS/call=1/1, inflight=32 (head=30 tail=30), Cachehit=23.53%
[...]
IOPS=916, IOS/call=1/1, inflight=32 (head=63 tail=63), Cachehit=59.06%
IOPS=882, IOS/call=1/1, inflight=32 (head=21 tail=32), Cachehit=61.79%
IOPS=984, IOS/call=1/1, inflight=32 (head=22 tail=22), Cachehit=63.87%
[...]
IOPS=1993, IOS/call=7/7, inflight=32 (head=58 tail=4), Cachehit=86.75%
IOPS=2260, IOS/call=5/5, inflight=32 (head=12 tail=16), Cachehit=87.15%
IOPS=1957, IOS/call=4/4, inflight=17 (head=7 tail=10), Cachehit=86.78%
[...]
IOPS=3606, IOS/call=7/7, inflight=32 (head=26 tail=35), Cachehit=93.47%
IOPS=3487, IOS/call=6/6, inflight=28 (head=23 tail=31), Cachehit=92.59%
IOPS=3379, IOS/call=7/7, inflight=26 (head=38 tail=40), Cachehit=92.66%
[...]
IOPS=4590, IOS/call=6/6, inflight=26 (head=38 tail=46), Cachehit=95.64%
IOPS=5464, IOS/call=7/7, inflight=28 (head=22 tail=24), Cachehit=95.94%
IOPS=4896, IOS/call=8/8, inflight=18 (head=44 tail=51), Cachehit=95.62%
[...]
IOPS=7736, IOS/call=8/8, inflight=24 (head=25 tail=29), Cachehit=97.35%
IOPS=6632, IOS/call=8/7, inflight=27 (head=54 tail=61), Cachehit=97.28%
IOPS=8488, IOS/call=8/8, inflight=22 (head=33 tail=39), Cachehit=97.33%
[...]
IOPS=10696, IOS/call=8/8, inflight=16 (head=63 tail=64), Cachehit=98.11%
IOPS=11874, IOS/call=7/7, inflight=17 (head=56 tail=56), Cachehit=98.31%
IOPS=11488, IOS/call=8/7, inflight=23 (head=54 tail=57), Cachehit=98.17%
[...]
IOPS=15472, IOS/call=8/8, inflight=17 (head=11 tail=17), Cachehit=98.58%
IOPS=18656, IOS/call=8/7, inflight=22 (head=50 tail=59), Cachehit=98.95%
IOPS=19408, IOS/call=8/8, inflight=18 (head=58 tail=63), Cachehit=99.01%
[...]
IOPS=54768, IOS/call=8/7, inflight=19 (head=63 tail=3), Cachehit=99.64%
IOPS=62888, IOS/call=8/7, inflight=21 (head=51 tail=53), Cachehit=99.73%
IOPS=71656, IOS/call=7/7, inflight=24 (head=28 tail=36), Cachehit=99.75%
[...]
IOPS=125320, IOS/call=8/8, inflight=22 (head=42 tail=46), Cachehit=99.85%
IOPS=201808, IOS/call=8/8, inflight=17 (head=27 tail=35), Cachehit=99.90%
IOPS=390325, IOS/call=7/7, inflight=22 (head=23 tail=27), Cachehit=99.94%
[...]
IOPS=834056, IOS/call=8/8, inflight=8 (head=23 tail=27), Cachehit=100.00%
IOPS=837520, IOS/call=8/8, inflight=8 (head=13 tail=17), Cachehit=100.00%
IOPS=833232, IOS/call=8/8, inflight=8 (head=51 tail=57), Cachehit=100.00%

It's also a nice visual into how high a cache hit rate has to be on a
rotational drive to make a substantial impact on performance.

Signed-off-by: Jens Axboe <axboe@kernel.dk>
t/aio-ring.c