Skip to content

Commit

Permalink
block: Change the granularity of io ticks from ms to ns
Browse files Browse the repository at this point in the history
Use ktime to change the granularity of IO accounting in block layer from
milli-seconds to nano-seconds to get the proper latency values for the
devices whose latency is in micro-seconds. After changing the granularity
to nano-seconds the iostat command, which was showing incorrect values for
%util, is now showing correct values.

We did not work on the patch to drop the logic for
STAT_PRECISE_TIMESTAMPS yet. Will do it if this patch is ok.

The iostat command was run after starting the fio with following command
on an NVME disk. For the same fio command, the iostat %util was showing
~100% for the disks whose latencies are in the range of microseconds.
With the kernel changes (granularity to nano-seconds), the %util was
showing correct values. Following are the details of the test and their
output:

fio command
-----------
[global]
bs=128K
iodepth=1
direct=1
ioengine=libaio
group_reporting
time_based
runtime=90
thinktime=1ms
numjobs=1
name=raw-write
rw=randrw
ignore_error=EIO:EIO
[job1]
filename=/dev/nvme0n1

Correct values after kernel changes:
====================================
iostat output
-------------
iostat -d /dev/nvme0n1 -x 1

Device            r_await w_await aqu-sz rareq-sz wareq-sz  svctm  %util
nvme0n1              0.08    0.05   0.06   128.00   128.00   0.07   6.50

Device            r_await w_await aqu-sz rareq-sz wareq-sz  svctm  %util
nvme0n1              0.08    0.06   0.06   128.00   128.00   0.07   6.30

Device            r_await w_await aqu-sz rareq-sz wareq-sz  svctm  %util
nvme0n1              0.06    0.05   0.06   128.00   128.00   0.06   5.70

From fio
--------
Read Latency: clat (usec): min=32, max=2335, avg=79.54, stdev=29.95
Write Latency: clat (usec): min=38, max=130, avg=57.76, stdev= 3.25

Values before kernel changes
============================
iostat output
-------------

iostat -d /dev/nvme0n1 -x 1

Device            r_await w_await aqu-sz rareq-sz wareq-sz  svctm  %util
nvme0n1              0.08    0.06   0.06   128.00   128.00   1.07  97.70

Device            r_await w_await aqu-sz rareq-sz wareq-sz  svctm  %util
nvme0n1              0.08    0.06   0.06   128.00   128.00   1.08  98.80

Device            r_await w_await aqu-sz rareq-sz wareq-sz  svctm  %util
nvme0n1              0.08    0.05   0.06   128.00   128.00   1.06  97.20

From fio
--------
Read Latency: clat (usec): min=33, max=468, avg=79.56, stdev=28.04
Write Latency: clat (usec): min=9, max=139, avg=57.10, stdev= 3.79

Signed-off-by: Junxiao Bi <junxiao.bi@oracle.com>
Signed-off-by: Gulam Mohamed <gulam.mohamed@oracle.com>
  • Loading branch information
gulams authored and intel-lab-lkp committed Dec 6, 2022
1 parent 035641b commit 317177b
Show file tree
Hide file tree
Showing 19 changed files with 50 additions and 50 deletions.
26 changes: 13 additions & 13 deletions block/blk-core.c
Expand Up @@ -912,12 +912,12 @@ int iocb_bio_iopoll(struct kiocb *kiocb, struct io_comp_batch *iob,
}
EXPORT_SYMBOL_GPL(iocb_bio_iopoll);

void update_io_ticks(struct block_device *part, unsigned long now, bool end)
void update_io_ticks(struct block_device *part, u64 now, bool end)
{
unsigned long stamp;
u64 stamp;
again:
stamp = READ_ONCE(part->bd_stamp);
if (unlikely(time_after(now, stamp))) {
if (unlikely(time_after64(now, stamp))) {
if (likely(try_cmpxchg(&part->bd_stamp, &stamp, now)))
__part_stat_add(part, io_ticks, end ? now - stamp : 1);
}
Expand All @@ -927,9 +927,9 @@ void update_io_ticks(struct block_device *part, unsigned long now, bool end)
}
}

unsigned long bdev_start_io_acct(struct block_device *bdev,
u64 bdev_start_io_acct(struct block_device *bdev,
unsigned int sectors, enum req_op op,
unsigned long start_time)
u64 start_time)
{
const int sgrp = op_stat_group(op);

Expand All @@ -949,7 +949,7 @@ EXPORT_SYMBOL(bdev_start_io_acct);
* @bio: bio to start account for
* @start_time: start time that should be passed back to bio_end_io_acct().
*/
void bio_start_io_acct_time(struct bio *bio, unsigned long start_time)
void bio_start_io_acct_time(struct bio *bio, u64 start_time)
{
bdev_start_io_acct(bio->bi_bdev, bio_sectors(bio),
bio_op(bio), start_time);
Expand All @@ -962,29 +962,29 @@ EXPORT_SYMBOL_GPL(bio_start_io_acct_time);
*
* Returns the start time that should be passed back to bio_end_io_acct().
*/
unsigned long bio_start_io_acct(struct bio *bio)
u64 bio_start_io_acct(struct bio *bio)
{
return bdev_start_io_acct(bio->bi_bdev, bio_sectors(bio),
bio_op(bio), jiffies);
bio_op(bio), ktime_get_ns());
}
EXPORT_SYMBOL_GPL(bio_start_io_acct);

void bdev_end_io_acct(struct block_device *bdev, enum req_op op,
unsigned long start_time)
u64 start_time)
{
const int sgrp = op_stat_group(op);
unsigned long now = READ_ONCE(jiffies);
unsigned long duration = now - start_time;
u64 now = ktime_get_ns();
u64 duration = now - start_time;

part_stat_lock();
update_io_ticks(bdev, now, true);
part_stat_add(bdev, nsecs[sgrp], jiffies_to_nsecs(duration));
part_stat_add(bdev, nsecs[sgrp], duration);
part_stat_local_dec(bdev, in_flight[op_is_write(op)]);
part_stat_unlock();
}
EXPORT_SYMBOL(bdev_end_io_acct);

void bio_end_io_acct_remapped(struct bio *bio, unsigned long start_time,
void bio_end_io_acct_remapped(struct bio *bio, u64 start_time,
struct block_device *orig_bdev)
{
bdev_end_io_acct(orig_bdev, bio_op(bio), start_time);
Expand Down
4 changes: 2 additions & 2 deletions block/blk-mq.c
Expand Up @@ -948,7 +948,7 @@ static void __blk_account_io_done(struct request *req, u64 now)
const int sgrp = op_stat_group(req_op(req));

part_stat_lock();
update_io_ticks(req->part, jiffies, true);
update_io_ticks(req->part, ktime_get_ns(), true);
part_stat_inc(req->part, ios[sgrp]);
part_stat_add(req->part, nsecs[sgrp], now - req->start_time_ns);
part_stat_unlock();
Expand Down Expand Up @@ -980,7 +980,7 @@ static void __blk_account_io_start(struct request *rq)
rq->part = rq->q->disk->part0;

part_stat_lock();
update_io_ticks(rq->part, jiffies, false);
update_io_ticks(rq->part, ktime_get_ns(), false);
part_stat_unlock();
}

Expand Down
2 changes: 1 addition & 1 deletion block/blk.h
Expand Up @@ -345,7 +345,7 @@ static inline bool blk_do_io_stat(struct request *rq)
return (rq->rq_flags & RQF_IO_STAT) && !blk_rq_is_passthrough(rq);
}

void update_io_ticks(struct block_device *part, unsigned long now, bool end);
void update_io_ticks(struct block_device *part, u64 now, bool end);

static inline void req_set_nomerge(struct request_queue *q, struct request *req)
{
Expand Down
8 changes: 4 additions & 4 deletions block/genhd.c
Expand Up @@ -956,7 +956,7 @@ ssize_t part_stat_show(struct device *dev,

if (inflight) {
part_stat_lock();
update_io_ticks(bdev, jiffies, true);
update_io_ticks(bdev, ktime_get_ns(), true);
part_stat_unlock();
}
part_stat_read_all(bdev, &stat);
Expand All @@ -976,7 +976,7 @@ ssize_t part_stat_show(struct device *dev,
(unsigned long long)stat.sectors[STAT_WRITE],
(unsigned int)div_u64(stat.nsecs[STAT_WRITE], NSEC_PER_MSEC),
inflight,
jiffies_to_msecs(stat.io_ticks),
(unsigned int)div_u64(stat.io_ticks, NSEC_PER_MSEC),
(unsigned int)div_u64(stat.nsecs[STAT_READ] +
stat.nsecs[STAT_WRITE] +
stat.nsecs[STAT_DISCARD] +
Expand Down Expand Up @@ -1245,7 +1245,7 @@ static int diskstats_show(struct seq_file *seqf, void *v)

if (inflight) {
part_stat_lock();
update_io_ticks(hd, jiffies, true);
update_io_ticks(hd, ktime_get_ns(), true);
part_stat_unlock();
}
part_stat_read_all(hd, &stat);
Expand All @@ -1268,7 +1268,7 @@ static int diskstats_show(struct seq_file *seqf, void *v)
(unsigned int)div_u64(stat.nsecs[STAT_WRITE],
NSEC_PER_MSEC),
inflight,
jiffies_to_msecs(stat.io_ticks),
(unsigned int)div_u64(stat.io_ticks, NSEC_PER_MSEC),
(unsigned int)div_u64(stat.nsecs[STAT_READ] +
stat.nsecs[STAT_WRITE] +
stat.nsecs[STAT_DISCARD] +
Expand Down
4 changes: 2 additions & 2 deletions drivers/block/drbd/drbd_debugfs.c
Expand Up @@ -105,7 +105,7 @@ static void seq_print_one_request(struct seq_file *m, struct drbd_request *req,
(s & RQ_WRITE) ? "W" : "R");

#define RQ_HDR_2 "\tstart\tin AL\tsubmit"
seq_printf(m, "\t%d", jiffies_to_msecs(now - req->start_jif));
seq_printf(m, "\t%d", jiffies_to_msecs(now - nsecs_to_jiffies(req->start_jif)));
seq_print_age_or_dash(m, s & RQ_IN_ACT_LOG, now - req->in_actlog_jif);
seq_print_age_or_dash(m, s & RQ_LOCAL_PENDING, now - req->pre_submit_jif);

Expand Down Expand Up @@ -171,7 +171,7 @@ static void seq_print_waiting_for_AL(struct seq_file *m, struct drbd_resource *r
/* if the oldest request does not wait for the activity log
* it is not interesting for us here */
if (req && !(req->rq_state & RQ_IN_ACT_LOG))
jif = req->start_jif;
jif = nsecs_to_jiffies(req->start_jif);
else
req = NULL;
spin_unlock_irq(&device->resource->req_lock);
Expand Down
2 changes: 1 addition & 1 deletion drivers/block/drbd/drbd_int.h
Expand Up @@ -300,7 +300,7 @@ struct drbd_request {
struct list_head req_pending_local;

/* for generic IO accounting */
unsigned long start_jif;
u64 start_jif;

/* for DRBD internal statistics */

Expand Down
4 changes: 2 additions & 2 deletions drivers/block/zram/zram_drv.c
Expand Up @@ -1662,7 +1662,7 @@ static int zram_rw_page(struct block_device *bdev, sector_t sector,
u32 index;
struct zram *zram;
struct bio_vec bv;
unsigned long start_time;
u64 start_time;

if (PageTransHuge(page))
return -ENOTSUPP;
Expand All @@ -1682,7 +1682,7 @@ static int zram_rw_page(struct block_device *bdev, sector_t sector,
bv.bv_offset = 0;

start_time = bdev_start_io_acct(bdev->bd_disk->part0,
SECTORS_PER_PAGE, op, jiffies);
SECTORS_PER_PAGE, op, ktime_get_ns());
ret = zram_bvec_rw(zram, &bv, index, offset, op, NULL);
bdev_end_io_acct(bdev->bd_disk->part0, op, start_time);
out:
Expand Down
10 changes: 5 additions & 5 deletions drivers/md/bcache/request.c
Expand Up @@ -476,7 +476,7 @@ struct search {
unsigned int cache_missed:1;

struct block_device *orig_bdev;
unsigned long start_time;
u64 start_time;

struct btree_op op;
struct data_insert_op iop;
Expand Down Expand Up @@ -714,7 +714,7 @@ static void search_free(struct closure *cl)

static inline struct search *search_alloc(struct bio *bio,
struct bcache_device *d, struct block_device *orig_bdev,
unsigned long start_time)
u64 start_time)
{
struct search *s;

Expand Down Expand Up @@ -1065,7 +1065,7 @@ static void cached_dev_nodata(struct closure *cl)

struct detached_dev_io_private {
struct bcache_device *d;
unsigned long start_time;
u64 start_time;
bio_end_io_t *bi_end_io;
void *bi_private;
struct block_device *orig_bdev;
Expand Down Expand Up @@ -1094,7 +1094,7 @@ static void detached_dev_end_io(struct bio *bio)
}

static void detached_dev_do_request(struct bcache_device *d, struct bio *bio,
struct block_device *orig_bdev, unsigned long start_time)
struct block_device *orig_bdev, u64 start_time)
{
struct detached_dev_io_private *ddip;
struct cached_dev *dc = container_of(d, struct cached_dev, disk);
Expand Down Expand Up @@ -1173,7 +1173,7 @@ void cached_dev_submit_bio(struct bio *bio)
struct block_device *orig_bdev = bio->bi_bdev;
struct bcache_device *d = orig_bdev->bd_disk->private_data;
struct cached_dev *dc = container_of(d, struct cached_dev, disk);
unsigned long start_time;
u64 start_time;
int rw = bio_data_dir(bio);

if (unlikely((d->c && test_bit(CACHE_SET_IO_DISABLE, &d->c->flags)) ||
Expand Down
2 changes: 1 addition & 1 deletion drivers/md/dm-core.h
Expand Up @@ -284,7 +284,7 @@ struct dm_io {
unsigned short magic;
blk_short_t flags;
spinlock_t lock;
unsigned long start_time;
u64 start_time;
void *data;
struct dm_io *next;
struct dm_stats_aux stats_aux;
Expand Down
8 changes: 4 additions & 4 deletions drivers/md/dm.c
Expand Up @@ -482,7 +482,7 @@ static int dm_blk_ioctl(struct block_device *bdev, fmode_t mode,

u64 dm_start_time_ns_from_clone(struct bio *bio)
{
return jiffies_to_nsecs(clone_to_tio(bio)->io->start_time);
return clone_to_tio(bio)->io->start_time;
}
EXPORT_SYMBOL_GPL(dm_start_time_ns_from_clone);

Expand All @@ -494,7 +494,7 @@ static bool bio_is_flush_with_data(struct bio *bio)
static void dm_io_acct(struct dm_io *io, bool end)
{
struct dm_stats_aux *stats_aux = &io->stats_aux;
unsigned long start_time = io->start_time;
u64 start_time = io->start_time;
struct mapped_device *md = io->md;
struct bio *bio = io->orig_bio;
unsigned int sectors;
Expand Down Expand Up @@ -527,7 +527,7 @@ static void dm_io_acct(struct dm_io *io, bool end)

dm_stats_account_io(&md->stats, bio_data_dir(bio),
sector, sectors,
end, start_time, stats_aux);
end, nsecs_to_jiffies(start_time), stats_aux);
}
}

Expand Down Expand Up @@ -589,7 +589,7 @@ static struct dm_io *alloc_io(struct mapped_device *md, struct bio *bio)
io->orig_bio = bio;
io->md = md;
spin_lock_init(&io->lock);
io->start_time = jiffies;
io->start_time = ktime_get_ns();
io->flags = 0;

if (static_branch_unlikely(&stats_enabled))
Expand Down
2 changes: 1 addition & 1 deletion drivers/md/md.h
Expand Up @@ -711,7 +711,7 @@ struct md_thread {

struct md_io_acct {
struct bio *orig_bio;
unsigned long start_time;
u64 start_time;
struct bio bio_clone;
};

Expand Down
2 changes: 1 addition & 1 deletion drivers/md/raid1.h
Expand Up @@ -157,7 +157,7 @@ struct r1bio {
sector_t sector;
int sectors;
unsigned long state;
unsigned long start_time;
u64 start_time;
struct mddev *mddev;
/*
* original bio going to /dev/mdx
Expand Down
2 changes: 1 addition & 1 deletion drivers/md/raid10.h
Expand Up @@ -123,7 +123,7 @@ struct r10bio {
sector_t sector; /* virtual sector number */
int sectors;
unsigned long state;
unsigned long start_time;
u64 start_time;
struct mddev *mddev;
/*
* original bio going to /dev/mdx
Expand Down
2 changes: 1 addition & 1 deletion drivers/md/raid5.c
Expand Up @@ -5474,7 +5474,7 @@ static void raid5_align_endio(struct bio *bi)
struct r5conf *conf;
struct md_rdev *rdev;
blk_status_t error = bi->bi_status;
unsigned long start_time = md_io_acct->start_time;
u64 start_time = md_io_acct->start_time;

bio_put(bi);

Expand Down
2 changes: 1 addition & 1 deletion drivers/nvdimm/btt.c
Expand Up @@ -1442,7 +1442,7 @@ static void btt_submit_bio(struct bio *bio)
struct bio_integrity_payload *bip = bio_integrity(bio);
struct btt *btt = bio->bi_bdev->bd_disk->private_data;
struct bvec_iter iter;
unsigned long start;
u64 start;
struct bio_vec bvec;
int err = 0;
bool do_acct;
Expand Down
2 changes: 1 addition & 1 deletion drivers/nvdimm/pmem.c
Expand Up @@ -202,7 +202,7 @@ static void pmem_submit_bio(struct bio *bio)
int ret = 0;
blk_status_t rc = 0;
bool do_acct;
unsigned long start;
u64 start;
struct bio_vec bvec;
struct bvec_iter iter;
struct pmem_device *pmem = bio->bi_bdev->bd_disk->private_data;
Expand Down
2 changes: 1 addition & 1 deletion include/linux/blk_types.h
Expand Up @@ -41,7 +41,7 @@ struct block_device {
sector_t bd_start_sect;
sector_t bd_nr_sectors;
struct disk_stats __percpu *bd_stats;
unsigned long bd_stamp;
u64 bd_stamp;
bool bd_read_only; /* read-only policy */
dev_t bd_dev;
atomic_t bd_openers;
Expand Down
14 changes: 7 additions & 7 deletions include/linux/blkdev.h
Expand Up @@ -1452,23 +1452,23 @@ static inline void blk_wake_io_task(struct task_struct *waiter)
wake_up_process(waiter);
}

unsigned long bdev_start_io_acct(struct block_device *bdev,
u64 bdev_start_io_acct(struct block_device *bdev,
unsigned int sectors, enum req_op op,
unsigned long start_time);
u64 start_time);
void bdev_end_io_acct(struct block_device *bdev, enum req_op op,
unsigned long start_time);
u64 start_time);

void bio_start_io_acct_time(struct bio *bio, unsigned long start_time);
unsigned long bio_start_io_acct(struct bio *bio);
void bio_end_io_acct_remapped(struct bio *bio, unsigned long start_time,
void bio_start_io_acct_time(struct bio *bio, u64 start_time);
u64 bio_start_io_acct(struct bio *bio);
void bio_end_io_acct_remapped(struct bio *bio, u64 start_time,
struct block_device *orig_bdev);

/**
* bio_end_io_acct - end I/O accounting for bio based drivers
* @bio: bio to end account for
* @start_time: start time returned by bio_start_io_acct()
*/
static inline void bio_end_io_acct(struct bio *bio, unsigned long start_time)
static inline void bio_end_io_acct(struct bio *bio, u64 start_time)
{
return bio_end_io_acct_remapped(bio, start_time, bio->bi_bdev);
}
Expand Down
2 changes: 1 addition & 1 deletion include/linux/part_stat.h
Expand Up @@ -10,7 +10,7 @@ struct disk_stats {
unsigned long sectors[NR_STAT_GROUPS];
unsigned long ios[NR_STAT_GROUPS];
unsigned long merges[NR_STAT_GROUPS];
unsigned long io_ticks;
u64 io_ticks;
local_t in_flight[2];
};

Expand Down

0 comments on commit 317177b

Please sign in to comment.