Re: [RFC PATCH] blk-mq: fixup RESTART when queue becomes idle

[Laurence Oberman]

On Thu, 2018-01-18 at 17:01 -0500, Mike Snitzer wrote:
> On Thu, Jan 18 2018 atÂÂ4:39pm -0500,
> Bart Van Assche <Bart.VanAssche@xxxxxxx> wrote:
> 
> > On Thu, 2018-01-18 at 16:23 -0500, Mike Snitzer wrote:
> > > On Thu, Jan 18 2018 atÂÂ3:58P -0500,
> > > Bart Van Assche <Bart.VanAssche@xxxxxxx> wrote:
> > > 
> > > > On Thu, 2018-01-18 at 15:48 -0500, Mike Snitzer wrote:
> > > > > For Bart's test the underlying scsi-mq driver is what is
> > > > > regularly
> > > > > hitting this case in __blk_mq_try_issue_directly():
> > > > > 
> > > > > ÂÂÂÂÂÂÂÂif (blk_mq_hctx_stopped(hctx) ||
> > > > > blk_queue_quiesced(q))
> > > > 
> > > > These lockups were all triggered by incorrect handling of
> > > > .queue_rq() returning BLK_STS_RESOURCE.
> > > 
> > > Please be precise, dm_mq_queue_rq()'s return of BLK_STS_RESOURCE?
> > > "Incorrect" because it no longer runs
> > > blk_mq_delay_run_hw_queue()?
> > 
> > In what I wrote I was referring to both dm_mq_queue_rq() and
> > scsi_queue_rq().
> > With "incorrect" I meant that queue lockups are introduced that
> > make user
> > space processes unkillable. That's a severe bug.
> 
> And yet Laurence cannot reproduce any such lockups with your test...
> 
> Are you absolutely certain this patch doesn't help you?
> https://patchwork.kernel.org/patch/10174037/
> 
> If it doesn't then that is actually very useful to know.
> 
> > > We have time to get this right, please stop hyperventilating
> > > about
> > > "regressions".
> > 
> > Sorry Mike but that's something I consider as an unfair comment. If
> > Ming and
> > you work on patches together, it's your job to make sure that no
> > regressions
> > are introduced. Instead of blaming me because I report these
> > regressions you
> > should be grateful that I take the time and effort to report these
> > regressions
> > early. And since you are employed by a large organization that
> > sells Linux
> > support services, your employer should invest in developing test
> > cases that
> > reach a higher coverage of the dm, SCSI and block layer code. I
> > don't think
> > that it's normal that my tests discovered several issues that were
> > not
> > discovered by Red Hat's internal test suite. That's something Red
> > Hat has to
> > address.
> 
> You have no self-awareness of just how mypoic you're being about
> this.
> 
> I'm not ignoring or blaming you for your test no longer passing.ÂÂFar
> from it.ÂÂI very much want to fix this.ÂÂBut I want it fixed in a way
> that doesn't paper over the real bug(s) while also introducing blind
> queue runs that compromise the blk-mq RESTART code's ability to work
> as
> intended.
> 
> I'd have thought you could appreciate this.ÂÂWe need a root cause on
> this, not hand-waving justifications on why problematic delayed queue
> runs are correct.
> 
> Please just focus on helping Laurence get his very capable testbed to
> reproduce this issue.ÂÂOnce we can reproduce these "unkillable"
> "stalls"
> in-house it'll be _much_ easier to analyze and fix.
> 
> Thanks,
> Mike

Hello Bart

OK, I ran 5 at once of 5 separate mount points.
I am using 4k block sizes
Its solid consistent for me. No stalls no gaps.

[global]
name=02-mq
filename=fio-output-02-mq.txt
rw=randwrite
verify=md5
;rwmixread=60
;rwmixwrite=40
bs=4K
;direct=1
;numjobs=4
;time_based=1
runtime=120

[file1]
size=3G
ioengine=libaio
iodepth=16

I watch I/O and I see it ramp up but fio still runs and it kind of
shuts down.

#!/bin/bash
for i in 1 2 3 4 5
do
	cd /data-$iÂ
	fio /root/srp-test.lobe/fio_tests/02-mq 1>/data-$i.out 2>&1 &
done


#TimeÂÂÂÂÂcpu sys interÂÂctxsw KBReadÂÂReads KBWrit WritesÂ

17:16:09ÂÂÂ34ÂÂ12 34431ÂÂ10393ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0 249872ÂÂ36094Â
17:16:10ÂÂÂ31ÂÂ10 13001ÂÂÂ2679ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ57652ÂÂÂ7980Â
17:16:11ÂÂÂ32ÂÂ11 19473ÂÂÂ4416ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0 143248ÂÂ17362Â
17:16:12ÂÂÂ31ÂÂÂ9ÂÂ8068ÂÂÂ1606ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ20088ÂÂÂ2026Â
17:16:13ÂÂÂ31ÂÂÂ9ÂÂ7718ÂÂÂ1518ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ15908ÂÂÂ1354Â
17:16:14ÂÂÂ36ÂÂ14 41132ÂÂÂ9710ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0 686216ÂÂ46661Â
17:16:15ÂÂÂ39ÂÂ18 63622ÂÂ21033ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ1246KÂÂ75108Â
17:16:16ÂÂÂ38ÂÂ16 76114ÂÂÂ9013ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ1146KÂÂ82338Â
17:16:17ÂÂÂ33ÂÂ11 31941ÂÂÂ2735ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0 237340ÂÂ25034Â
17:16:18ÂÂÂ36ÂÂ14 23900ÂÂÂ4982ÂÂÂÂÂÂ0ÂÂÂÂÂÂ1ÂÂ1567KÂÂ43244Â
17:16:19ÂÂÂ37ÂÂ15 55884ÂÂÂ4974ÂÂÂÂÂÂ0ÂÂÂÂÂÂ4ÂÂ1003KÂÂ67253Â
17:16:20ÂÂÂ28ÂÂ12ÂÂ7542ÂÂÂ4975ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ1630KÂÂÂ3266Â
17:16:21ÂÂÂÂ8ÂÂÂ6 14650ÂÂ34721ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ2535KÂÂ21206Â
17:16:22ÂÂÂÂ2ÂÂÂ2ÂÂ6655ÂÂ15839ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ2319KÂÂÂ9897Â
17:16:23ÂÂÂ11ÂÂ11 37305 134030ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0ÂÂ1275KÂÂ87010Â
17:16:24ÂÂÂ23ÂÂ22 59266 119350ÂÂÂ6560ÂÂÂ1640ÂÂ1102KÂÂ78034Â
17:16:25ÂÂÂ21ÂÂ17 65699 144462 148052ÂÂ37013 159900ÂÂ22120Â
17:16:26ÂÂÂ14ÂÂÂ9 80700 164034 216588ÂÂ54147ÂÂÂÂÂÂ4ÂÂÂÂÂÂ1Â
#ÂÂÂÂÂÂÂÂÂ<----CPU[HYPER]-----><----------Disks----------->
#TimeÂÂÂÂÂcpu sys interÂÂctxsw KBReadÂÂReads KBWrit WritesÂ
17:16:27ÂÂÂ14ÂÂÂ9 78699 162095 214412ÂÂ53603ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:28ÂÂÂ14ÂÂÂ9 75895 155352 204932ÂÂ51233ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:29ÂÂÂ14ÂÂÂ9 75377 161871 214136ÂÂ53534ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:30ÂÂÂ16ÂÂ11 79298 155967 206164ÂÂ51541ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:31ÂÂÂ14ÂÂÂ8 82281 165266 218652ÂÂ54662ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:32ÂÂÂ14ÂÂÂ9 88635 163302 215876ÂÂ53970ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:33ÂÂÂ14ÂÂÂ8 88755 168958 223568ÂÂ55892ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:34ÂÂÂ15ÂÂÂ9 82073 154321 203936ÂÂ50984ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:35ÂÂÂ17ÂÂ10 87004 161467 213308ÂÂ53327ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:36ÂÂÂ15ÂÂÂ9 86198 161247 212940ÂÂ53235ÂÂÂÂÂÂ4ÂÂÂÂÂÂ1Â
17:16:37ÂÂÂ15ÂÂÂ9 83429 162890 215276ÂÂ53819ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:38ÂÂÂ16ÂÂ10 83272 160611 212264ÂÂ53066ÂÂÂÂÂ20ÂÂÂÂÂÂ2Â
17:16:39ÂÂÂ16ÂÂ10 93850 168179 222376ÂÂ55594ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:40ÂÂÂ15ÂÂÂ9 86801 167507 221372ÂÂ55343ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:41ÂÂÂ14ÂÂÂ8 82688 171249 226560ÂÂ56640ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:42ÂÂÂ14ÂÂÂ8 86202 159171 210344ÂÂ52586ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:43ÂÂÂ16ÂÂ10 86063 156009 206328ÂÂ51582ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:44ÂÂÂ16ÂÂ10 90927 153961 203584ÂÂ50896ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:45ÂÂÂ15ÂÂÂ9 95084 156370 206844ÂÂ51710ÂÂÂÂ132ÂÂÂÂÂ13Â
17:16:46ÂÂÂ14ÂÂÂ8 85572 158469 209300ÂÂ52326ÂÂÂÂÂÂ4ÂÂÂÂÂÂ1Â
17:16:47ÂÂÂ14ÂÂÂ8 92075 158469 209600ÂÂ52400ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:48ÂÂÂ16ÂÂ10 95469 154772 204176ÂÂ51044ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
#ÂÂÂÂÂÂÂÂÂ<----CPU[HYPER]-----><----------Disks----------->
#TimeÂÂÂÂÂcpu sys interÂÂctxsw KBReadÂÂReads KBWrit WritesÂ
17:16:49ÂÂÂ15ÂÂ10 93856 154182 203568ÂÂ50897ÂÂÂÂÂÂ5ÂÂÂÂÂÂ5Â
17:16:50ÂÂÂ15ÂÂ10 92308 151964 200680ÂÂ50170ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:51ÂÂÂ16ÂÂ10 94035 155076 204868ÂÂ51217ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:52ÂÂÂ15ÂÂÂ9 93949 164969 217980ÂÂ54495ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:53ÂÂÂ14ÂÂÂ9 85744 149553 197428ÂÂ49357ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:54ÂÂÂ14ÂÂÂ9 83064 155788 205684ÂÂ51421ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:55ÂÂÂ16ÂÂ10 83579 166084 218480ÂÂ54620ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:56ÂÂÂ15ÂÂÂ9 74766 158728 208556ÂÂ52139ÂÂÂÂÂÂ4ÂÂÂÂÂÂ1Â
17:16:57ÂÂÂ14ÂÂÂ9 82944 162720 215116ÂÂ53779ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:58ÂÂÂ12ÂÂÂ7 88529 163814 216440ÂÂ54110ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:16:59ÂÂÂ14ÂÂÂ7 85936 166723 220372ÂÂ55093ÂÂÂÂÂÂ4ÂÂÂÂÂÂ1Â
17:17:00ÂÂÂ13ÂÂÂ8 86701 153728 203052ÂÂ50763ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:01ÂÂÂ14ÂÂÂ9 92859 155963 205972ÂÂ51493ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:02ÂÂÂ13ÂÂÂ8 85624 143746 189756ÂÂ47439ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:03ÂÂÂ13ÂÂÂ8 85029 142540 188044ÂÂ47010ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:04ÂÂÂ14ÂÂÂ8 87291 144790 191148ÂÂ47788ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:05ÂÂÂ14ÂÂÂ8 81922 144342 190544ÂÂ47636ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:06ÂÂÂ14ÂÂÂ8 81587 161043 212576ÂÂ53144ÂÂÂÂÂÂ8ÂÂÂÂÂÂ2Â
17:17:07ÂÂÂ15ÂÂÂ8 85080 142285 187688ÂÂ46922ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:08ÂÂÂ13ÂÂÂ8 86980 150246 197852ÂÂ49463ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:09ÂÂÂ12ÂÂÂ8 81388 144335 190312ÂÂ47578ÂÂÂÂÂÂ4ÂÂÂÂÂÂ1Â
17:17:10ÂÂÂ13ÂÂÂ8 88436 146957 194040ÂÂ48510ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
#ÂÂÂÂÂÂÂÂÂ<----CPU[HYPER]-----><----------Disks----------->
#TimeÂÂÂÂÂcpu sys interÂÂctxsw KBReadÂÂReads KBWrit WritesÂ
17:17:11ÂÂÂ11ÂÂÂ7 78997 137847 181828ÂÂ45457ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:12ÂÂÂ12ÂÂÂ8 85709 148847 196708ÂÂ49177ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:13ÂÂÂ17ÂÂ10 97228 170646 225528ÂÂ56382ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:14ÂÂÂ14ÂÂÂ9 96032 173474 229400ÂÂ57350ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:15ÂÂÂ15ÂÂÂ9 95340 167951 221848ÂÂ55462ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:16ÂÂÂ16ÂÂ10 87392 157489 207748ÂÂ51937ÂÂÂÂÂ38ÂÂÂÂÂÂ5Â
17:17:17ÂÂÂ16ÂÂ10 84756 152753 201716ÂÂ50429ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:18ÂÂÂ17ÂÂ10 85109 153000 202080ÂÂ50520ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:19ÂÂÂ16ÂÂ10 92109 164514 217396ÂÂ54349ÂÂÂÂÂ80ÂÂÂÂÂÂ5Â
17:17:20ÂÂÂ15ÂÂÂ9 91342 155674 205804ÂÂ51451ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:21ÂÂÂ12ÂÂÂ7 73921 126577 167060ÂÂ41765ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:22ÂÂÂ13ÂÂÂ8 76916 126701 167176ÂÂ41794ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:23ÂÂÂ13ÂÂÂ8 85187 151074 199768ÂÂ49942ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:24ÂÂÂ15ÂÂÂ9 85737 153664 203168ÂÂ50792ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:25ÂÂÂ15ÂÂÂ9 87113 147636 195084ÂÂ48771ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:26ÂÂÂ14ÂÂÂ8 89440 157433 208116ÂÂ52029ÂÂÂÂÂÂ4ÂÂÂÂÂÂ1Â
17:17:27ÂÂÂ14ÂÂÂ9 95290 172224 227036ÂÂ56759ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:28ÂÂÂ15ÂÂ10 93918 167611 220164ÂÂ55041ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:29ÂÂÂ13ÂÂÂ8 82404 149274 197312ÂÂ49328ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:30ÂÂÂ10ÂÂÂ7 75961 138276 182668ÂÂ45667ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:31ÂÂÂ12ÂÂÂ8 84899 151829 200764ÂÂ50191ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:32ÂÂÂ13ÂÂÂ8 81386 141091 186444ÂÂ46611ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:33ÂÂÂ15ÂÂÂ9ÂÂ100K 167489 221640ÂÂ55410ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:34ÂÂÂ14ÂÂÂ9 89601 158765 210032ÂÂ52508ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:35ÂÂÂ14ÂÂÂ9 92440 155287 205216ÂÂ51304ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:36ÂÂÂ15ÂÂ10 90042 155934 206168ÂÂ51542ÂÂÂÂÂÂ4ÂÂÂÂÂÂ1Â
17:17:37ÂÂÂ14ÂÂÂ9 91670 164456 217684ÂÂ54421ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:38ÂÂÂ14ÂÂÂ9 78612 167368 221348ÂÂ55337ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:39ÂÂÂ15ÂÂÂ9 91325 162599 214616ÂÂ53654ÂÂÂÂÂÂ0ÂÂÂÂÂÂ0Â
17:17:40ÂÂÂ14ÂÂÂ9 79112 151595 199984ÂÂ50000ÂÂÂÂÂ21ÂÂÂÂÂÂ8Â
17:17:41ÂÂÂÂ9ÂÂÂ3 32565ÂÂ60936ÂÂ79832ÂÂ19964ÂÂÂÂÂ32ÂÂÂÂÂ12Â