Re: [PATCH RFC] block: fix inaccurate io_ticks

[Weiping Zhang <zwp10758@gmail.com>]

On Fri, Oct 23, 2020 at 5:11 PM Ming Lei <ming.lei@redhat.com> wrote:
>
> On Fri, Oct 23, 2020 at 04:56:08PM +0800, Weiping Zhang wrote:
> > On Fri, Oct 23, 2020 at 4:49 PM Ming Lei <ming.lei@redhat.com> wrote:
> > >
> > > On Fri, Oct 23, 2020 at 02:46:32PM +0800, Weiping Zhang wrote:
> > > > Do not add io_ticks if there is no infligh io when start a new IO,
> > > > otherwise an extra 1 jiffy will be add to this IO.
> > > >
> > > > I run the following command on a host, with different kernel version.
> > > >
> > > > fio -name=test -ioengine=sync -bs=4K -rw=write
> > > > -filename=/home/test.fio.log -size=100M -time_based=1 -direct=1
> > > > -runtime=300 -rate=2m,2m
> > > >
> > > > If we run fio in a sync direct io mode, IO will be proccessed one by one,
> > > > you can see that there are 512 IOs completed in one second.
> > > >
> > > > kernel: 4.19.0
> > > >
> > > > Device: rrqm/s wrqm/s  r/s    w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
> > > > vda       0.00   0.00 0.00 512.00  0.00  2.00     8.00     0.21  0.40    0.00    0.40  0.40 20.60
> > > >
> > > > The averate io.latency is 0.4ms, so the disk time cost in one second
> > > > should be 0.4 * 512 = 204.8 ms, that means, %util should be 20%.
> > > >
> > > > Becase update_io_ticks will add a extra 1 jiffy(1ms) for every IO, the
> > > > io.latency io.latency will be 1 + 0.4 = 1.4ms,
> > > > 1.4 * 512 = 716.8ms, so the %util show it about 72%.
> > > >
> > > > Device  r/s    w/s rMB/s wMB/s rrqm/s wrqm/s %rrqm %wrqm r_await w_await aqu-sz rareq-sz wareq-sz svctm  %util
> > > > vda    0.00 512.00  0.00  2.00   0.00   0.00  0.00  0.00    0.00    0.40   0.20     0.00     4.00  1.41  72.10
> > > >
> > > > After this patch:
> > > > Device  r/s    w/s rMB/s wMB/s rrqm/s wrqm/s %rrqm %wrqm r_await w_await aqu-sz rareq-sz wareq-sz svctm  %util
> > > > vda    0.00 512.00  0.00  2.00   0.00   0.00  0.00  0.00    0.00    0.40   0.20     0.00     4.00  0.39  20.00
> > > >
> > > > Fixes: 5b18b5a73760 ("block: delete part_round_stats and switch to less precise counting")
> > > > Signed-off-by: Weiping Zhang <zhangweiping@didiglobal.com>
> > > > ---
> > > >  block/blk-core.c | 19 ++++++++++++++-----
> > > >  block/blk.h      |  1 +
> > > >  block/genhd.c    |  2 +-
> > > >  3 files changed, 16 insertions(+), 6 deletions(-)
> > > >
> > > > diff --git a/block/blk-core.c b/block/blk-core.c
> > > > index ac00d2fa4eb4..789a5c40b6a6 100644
> > > > --- a/block/blk-core.c
> > > > +++ b/block/blk-core.c
> > > > @@ -1256,14 +1256,14 @@ unsigned int blk_rq_err_bytes(const struct request *rq)
> > > >  }
> > > >  EXPORT_SYMBOL_GPL(blk_rq_err_bytes);
> > > >
> > > > -static void update_io_ticks(struct hd_struct *part, unsigned long now, bool end)
> > > > +static void update_io_ticks(struct hd_struct *part, unsigned long now, bool inflight)
> > > >  {
> > > >       unsigned long stamp;
> > > >  again:
> > > >       stamp = READ_ONCE(part->stamp);
> > > >       if (unlikely(stamp != now)) {
> > > > -             if (likely(cmpxchg(&part->stamp, stamp, now) == stamp))
> > > > -                     __part_stat_add(part, io_ticks, end ? now - stamp : 1);
> > > > +             if (likely(cmpxchg(&part->stamp, stamp, now) == stamp) && inflight)
> > > > +                     __part_stat_add(part, io_ticks, now - stamp);
> > > >       }
> > > >       if (part->partno) {
> > > >               part = &part_to_disk(part)->part0;
> > > > @@ -1310,13 +1310,20 @@ void blk_account_io_done(struct request *req, u64 now)
> > > >
> > > >  void blk_account_io_start(struct request *rq)
> > > >  {
> > > > +     struct hd_struct *part;
> > > > +     struct request_queue *q;
> > > > +     int inflight;
> > > > +
> > > >       if (!blk_do_io_stat(rq))
> > > >               return;
> > > >
> > > >       rq->part = disk_map_sector_rcu(rq->rq_disk, blk_rq_pos(rq));
> > > >
> > > >       part_stat_lock();
> > > > -     update_io_ticks(rq->part, jiffies, false);
> > > > +     part = rq->part;
> > > > +     q = part_to_disk(part)->queue;
> > > > +     inflight = blk_mq_in_flight(q, part);
> > > > +     update_io_ticks(part, jiffies, inflight > 0 ? true : false);
> > >
> > > Yeah, this account issue can be fixed by applying such 'inflight' info.
> > > However, blk_mq_in_flight() isn't cheap enough, I did get soft lockup
> > > report because of blk_mq_in_flight() called in I/O path.
Hello Ming,

Can you share your test script ?
> > > BTW, this way is just like reverting 5b18b5a73760 ("block: delete
> > > part_round_stats and switch to less precise counting").
> > >
> > >
> > Hello Ming,
> >
> > Shall we switch it to atomic mode ? update inflight_count when
> > start/done for every IO.
>
> That is more expensive than blk_mq_in_flight().
>
> > Or any other cheaper way.
>
> I guess it is hard to figure out one cheaper way to figure out
> IO in-flight count especially in case of multiple CPU cores and
> Millions of IOPS.
>

For io_ticks, we only need to know if there is any inflight IO and do
not care how many
inflight IOs. So an optimization at here is to test any set bit in
tagset, return true directly,
it will save some cpu cycles in most of case. Send v2 later.

Thanks
Weiping