very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Alex Xu (Hello71)]

Hi,

I recently noticed that between 6441998e2e and 9eaa88c703, I/O became 
much slower on my machine using ext4 on dm-crypt on NVMe with bfq 
scheduler. Checking iostat during heavy usage (find / -xdev and fstrim 
-v /), maximum IOPS had fallen from ~10000 to ~100. Reverting cb2ac2912a 
("block: reduce kblockd_mod_delayed_work_on() CPU consumption") resolves 
the issue.

Thanks,
Alex.

Re: very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Jens Axboe]

On 12/18/21 11:57 AM, Alex Xu (Hello71) wrote:
> Hi,
> 
> I recently noticed that between 6441998e2e and 9eaa88c703, I/O became 
> much slower on my machine using ext4 on dm-crypt on NVMe with bfq 
> scheduler. Checking iostat during heavy usage (find / -xdev and fstrim 
> -v /), maximum IOPS had fallen from ~10000 to ~100. Reverting cb2ac2912a 
> ("block: reduce kblockd_mod_delayed_work_on() CPU consumption") resolves 
> the issue.

Hmm interesting. I'll try and see if I can reproduce this and come up
with a fix.

-- 
Jens Axboe

Re: very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Jens Axboe]

On 12/18/21 12:02 PM, Jens Axboe wrote:
> On 12/18/21 11:57 AM, Alex Xu (Hello71) wrote:
>> Hi,
>>
>> I recently noticed that between 6441998e2e and 9eaa88c703, I/O became 
>> much slower on my machine using ext4 on dm-crypt on NVMe with bfq 
>> scheduler. Checking iostat during heavy usage (find / -xdev and fstrim 
>> -v /), maximum IOPS had fallen from ~10000 to ~100. Reverting cb2ac2912a 
>> ("block: reduce kblockd_mod_delayed_work_on() CPU consumption") resolves 
>> the issue.
> 
> Hmm interesting. I'll try and see if I can reproduce this and come up
> with a fix.

I can reproduce this. Alex, can you see if this one helps? Trying to see
if we can hit a happy medium here that avoids hammering on that timer,
but it really depends on what the mix is here of delay with pending,
or no delay with no pending.

Dexuan, can you test this for your test case too? I'm going to queue
up a revert for -rc6 just in case.

diff --git a/block/blk-core.c b/block/blk-core.c
index c1833f95cb97..a3fbf4360ee9 100644
--- a/block/blk-core.c
+++ b/block/blk-core.c
@@ -1481,12 +1481,15 @@ int kblockd_schedule_work(struct work_struct *work)
 }
 EXPORT_SYMBOL(kblockd_schedule_work);
 
-int kblockd_mod_delayed_work_on(int cpu, struct delayed_work *dwork,
-				unsigned long delay)
-{
-	if (!delay)
-		return queue_work_on(cpu, kblockd_workqueue, &dwork->work);
-	return mod_delayed_work_on(cpu, kblockd_workqueue, dwork, delay);
+void kblockd_mod_delayed_work_on(int cpu, struct delayed_work *dwork,
+				 unsigned long delay)
+{
+	if (!delay) {
+		cancel_delayed_work(dwork);
+		queue_work_on(cpu, kblockd_workqueue, &dwork->work);
+	} else {
+		mod_delayed_work_on(cpu, kblockd_workqueue, dwork, delay);
+	}
 }
 EXPORT_SYMBOL(kblockd_mod_delayed_work_on);
 
diff --git a/include/linux/blkdev.h b/include/linux/blkdev.h
index bd4370baccca..1c7ba45e8463 100644
--- a/include/linux/blkdev.h
+++ b/include/linux/blkdev.h
@@ -1159,7 +1159,7 @@ static inline unsigned int block_size(struct block_device *bdev)
 }
 
 int kblockd_schedule_work(struct work_struct *work);
-int kblockd_mod_delayed_work_on(int cpu, struct delayed_work *dwork, unsigned long delay);
+void kblockd_mod_delayed_work_on(int cpu, struct delayed_work *dwork, unsigned long delay);
 
 #define MODULE_ALIAS_BLOCKDEV(major,minor) \
 	MODULE_ALIAS("block-major-" __stringify(major) "-" __stringify(minor))


-- 
Jens Axboe

Re: very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Jens Axboe]

On 12/19/21 7:58 AM, Jens Axboe wrote:
> On 12/18/21 12:02 PM, Jens Axboe wrote:
>> On 12/18/21 11:57 AM, Alex Xu (Hello71) wrote:
>>> Hi,
>>>
>>> I recently noticed that between 6441998e2e and 9eaa88c703, I/O became 
>>> much slower on my machine using ext4 on dm-crypt on NVMe with bfq 
>>> scheduler. Checking iostat during heavy usage (find / -xdev and fstrim 
>>> -v /), maximum IOPS had fallen from ~10000 to ~100. Reverting cb2ac2912a 
>>> ("block: reduce kblockd_mod_delayed_work_on() CPU consumption") resolves 
>>> the issue.
>>
>> Hmm interesting. I'll try and see if I can reproduce this and come up
>> with a fix.
> 
> I can reproduce this. Alex, can you see if this one helps? Trying to see
> if we can hit a happy medium here that avoids hammering on that timer,
> but it really depends on what the mix is here of delay with pending,
> or no delay with no pending.
> 
> Dexuan, can you test this for your test case too? I'm going to queue
> up a revert for -rc6 just in case.

This one should be better...


diff --git a/block/blk-core.c b/block/blk-core.c
index c1833f95cb97..5e9e3c2b7a94 100644
--- a/block/blk-core.c
+++ b/block/blk-core.c
@@ -1481,12 +1481,17 @@ int kblockd_schedule_work(struct work_struct *work)
 }
 EXPORT_SYMBOL(kblockd_schedule_work);
 
-int kblockd_mod_delayed_work_on(int cpu, struct delayed_work *dwork,
-				unsigned long delay)
+void kblockd_mod_delayed_work_on(int cpu, struct delayed_work *dwork,
+				 unsigned long msecs)
 {
-	if (!delay)
-		return queue_work_on(cpu, kblockd_workqueue, &dwork->work);
-	return mod_delayed_work_on(cpu, kblockd_workqueue, dwork, delay);
+	if (!msecs) {
+		cancel_delayed_work(dwork);
+		queue_work_on(cpu, kblockd_workqueue, &dwork->work);
+	} else {
+		unsigned long delay = msecs_to_jiffies(msecs);
+
+		mod_delayed_work_on(cpu, kblockd_workqueue, dwork, delay);
+	}
 }
 EXPORT_SYMBOL(kblockd_mod_delayed_work_on);
 
diff --git a/block/blk-mq.c b/block/blk-mq.c
index 8874a63ae952..95288a98dae1 100644
--- a/block/blk-mq.c
+++ b/block/blk-mq.c
@@ -1155,8 +1155,7 @@ EXPORT_SYMBOL(blk_mq_kick_requeue_list);
 void blk_mq_delay_kick_requeue_list(struct request_queue *q,
 				    unsigned long msecs)
 {
-	kblockd_mod_delayed_work_on(WORK_CPU_UNBOUND, &q->requeue_work,
-				    msecs_to_jiffies(msecs));
+	kblockd_mod_delayed_work_on(WORK_CPU_UNBOUND, &q->requeue_work, msecs);
 }
 EXPORT_SYMBOL(blk_mq_delay_kick_requeue_list);
 
@@ -1868,7 +1867,7 @@ static void __blk_mq_delay_run_hw_queue(struct blk_mq_hw_ctx *hctx, bool async,
 	}
 
 	kblockd_mod_delayed_work_on(blk_mq_hctx_next_cpu(hctx), &hctx->run_work,
-				    msecs_to_jiffies(msecs));
+					msecs);
 }
 
 /**
diff --git a/include/linux/blkdev.h b/include/linux/blkdev.h
index bd4370baccca..40748eedddbb 100644
--- a/include/linux/blkdev.h
+++ b/include/linux/blkdev.h
@@ -1159,7 +1159,7 @@ static inline unsigned int block_size(struct block_device *bdev)
 }
 
 int kblockd_schedule_work(struct work_struct *work);
-int kblockd_mod_delayed_work_on(int cpu, struct delayed_work *dwork, unsigned long delay);
+void kblockd_mod_delayed_work_on(int cpu, struct delayed_work *dwork, unsigned long msecs);
 
 #define MODULE_ALIAS_BLOCKDEV(major,minor) \
 	MODULE_ALIAS("block-major-" __stringify(major) "-" __stringify(minor))

-- 
Jens Axboe

RE: very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Dexuan Cui]

> From: Jens Axboe <axboe@kernel.dk>
> Sent: Sunday, December 19, 2021 7:28 AM
> > ...
> > Dexuan, can you test this for your test case too? I'm going to queue
> > up a revert for -rc6 just in case.
> 
> This one should be better...
> ...
> Jens Axboe

Hi Jens, sorry -- unluckily I lost the test environment.. :-(
I pinged the user to set up the test environment again, but he's
on vacation till the beginning of January.

Re: RE: very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Yin Fengwei]

Hi Jens, Dexuan,

On 12/20/2021 1:15 PM, Dexuan Cui wrote:
>> From: Jens Axboe <axboe@kernel.dk>
>> Sent: Sunday, December 19, 2021 7:28 AM
>>> ...
>>> Dexuan, can you test this for your test case too? I'm going to queue
>>> up a revert for -rc6 just in case.
>>
>> This one should be better...
>> ...
>> Jens Axboe
> 
> Hi Jens, sorry -- unluckily I lost the test environment.. :-(
> I pinged the user to set up the test environment again, but he's
> on vacation till the beginning of January.

We hit this issue in our testing env also and will help to verify
your fixing patch. Thanks.


Regards
Yin, Fengwei

RE: RE: very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Dexuan Cui]

> From: Oliver Sang <oliver.sang@intel.com>
> Sent: Tuesday, December 28, 2021 5:49 AM
>  ...
> Hi Jens, Dexuan,
> 
> On Tue, Dec 28, 2021 at 10:30:43AM +0800, Yin Fengwei wrote:
> > Hi Jens, Dexuan,
> >
> > On 12/20/2021 1:15 PM, Dexuan Cui wrote:
> > >> From: Jens Axboe <axboe@kernel.dk>
> > >> Sent: Sunday, December 19, 2021 7:28 AM
> > >>> ...
> > >>> Dexuan, can you test this for your test case too? I'm going to queue
> > >>> up a revert for -rc6 just in case.
> > >>
> > >> This one should be better...
> > >> ...
> > >> Jens Axboe
> > >
> > > Hi Jens, sorry -- unluckily I lost the test environment.. :-(
> > > I pinged the user to set up the test environment again, but he's
> > > on vacation till the beginning of January.
> >
> > We hit this issue in our testing env also and will help to verify
> > your fixing patch. Thanks.
> 
> as we reported in [1], we found cb2ac2912a cause big regressions in fxmark
> tests.
> "[block]  cb2ac2912a:
> fxmark.ssd_f2fs_dbench_client_4_bufferedio.works/sec -66.0% regression"
> 
> By applying the patch supplied by Jens Axboe in previous thread directly
> upon cb2ac2912a, we confirmed the regression could be fixed:
> ...
> > Regards
> > Yin, Fengwei

Hi Jens, Fengwei,
I finally regained my test evnironment and tested Jens's Dec-19 patch
(see https://www.spinics.net/lists/linux-block/msg78065.html) and it
also worked fine for me, i.e. no excessive CPU utilization even with the
default dm_mod.dm_mq_queue_depth=2048. 

BTW, Jen's patch is not in the mainline yet. I tested it using the linux-block tree.

Thanks,
-- Dexuan

RE: RE: very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Dexuan Cui]

> From: Dexuan Cui
> Sent: Friday, January 21, 2022 10:15 PM
> To: Oliver Sang <oliver.sang@intel.com>; Jens Axboe <axboe@kernel.dk>; Yin
> Fengwei <fengwei.yin@intel.com>; linux-block@vger.kernel.org
> Cc: Alex Xu (Hello71) <alex_y_xu@yahoo.ca>; ming.lei@redhat.com;
> hch@lst.de; Long Li <longli@microsoft.com>; Michael Kelley (LINUX)
> <mikelley@microsoft.com>; linux-kernel@vger.kernel.org; Li, Philip
> <philip.li@intel.com>; Rakesh Ginjupalli <Rakesh.Ginjupalli@microsoft.com>
> Subject: RE: RE: very low IOPS due to "block: reduce
> kblockd_mod_delayed_work_on() CPU consumption"
> 
> > From: Oliver Sang <oliver.sang@intel.com>
> > Sent: Tuesday, December 28, 2021 5:49 AM
> >  ...
> > Hi Jens, Dexuan,
> >
> > On Tue, Dec 28, 2021 at 10:30:43AM +0800, Yin Fengwei wrote:
> > > Hi Jens, Dexuan,
> > >
> > > On 12/20/2021 1:15 PM, Dexuan Cui wrote:
> > > >> From: Jens Axboe <axboe@kernel.dk>
> > > >> Sent: Sunday, December 19, 2021 7:28 AM
> > > >>> ...
> > > >>> Dexuan, can you test this for your test case too? I'm going to queue
> > > >>> up a revert for -rc6 just in case.
> > > >>
> > > >> This one should be better...
> > > >> ...
> > > >> Jens Axboe
> > > >
> > > > Hi Jens, sorry -- unluckily I lost the test environment.. :-(
> > > > I pinged the user to set up the test environment again, but he's
> > > > on vacation till the beginning of January.
> > >
> > > We hit this issue in our testing env also and will help to verify
> > > your fixing patch. Thanks.
> >
> > as we reported in [1], we found cb2ac2912a cause big regressions in fxmark
> > tests.
> > "[block]  cb2ac2912a:
> > fxmark.ssd_f2fs_dbench_client_4_bufferedio.works/sec -66.0% regression"
> >
> > By applying the patch supplied by Jens Axboe in previous thread directly
> > upon cb2ac2912a, we confirmed the regression could be fixed:
> > ...
> > > Regards
> > > Yin, Fengwei
> 
> Hi Jens, Fengwei,
> I finally regained my test evnironment and tested Jens's Dec-19 patch
> (see https://www.spinics.net/lists/linux-block/msg78065.html) and it
> also worked fine for me, i.e. no excessive CPU utilization even with the
> default dm_mod.dm_mq_queue_depth=2048.
> 
> BTW, Jen's patch is not in the mainline yet. I tested it using the linux-block tree.
> 
> Thanks,
> -- Dexuan

Hi Jens, any plan to commit your 12/19/2021 patch? 
It works great according to Fengwei's and my test.

Re: very low IOPS due to "block: reduce kblockd_mod_delayed_work_on() CPU consumption"

[Christoph Hellwig]

On Sun, Dec 19, 2021 at 08:28:18AM -0700, Jens Axboe wrote:
> > 
> > Dexuan, can you test this for your test case too? I'm going to queue
> > up a revert for -rc6 just in case.
> 
> This one should be better...

We might just want something like a revert of
9f993737906b30d7b2454a38637d1f70ffd60f2f.

Or just always use a normal work queue for run_work, and then use a
timer to schedule it for the relatively rare delayed case.