On 8/20/18 1:08 PM, Jens Axboe wrote: > On 8/20/18 11:34 AM, van der Linden, Frank wrote: >> On 8/20/18 9:37 AM, Jens Axboe wrote: >>> On 8/7/18 3:19 PM, Jens Axboe wrote: >>>> On 8/7/18 3:12 PM, Anchal Agarwal wrote: >>>>> On Tue, Aug 07, 2018 at 02:39:48PM -0600, Jens Axboe wrote: >>>>>> On 8/7/18 2:12 PM, Anchal Agarwal wrote: >>>>>>> On Tue, Aug 07, 2018 at 08:29:44AM -0600, Jens Axboe wrote: >>>>>>>> On 8/1/18 4:09 PM, Jens Axboe wrote: >>>>>>>>> On 8/1/18 11:06 AM, Anchal Agarwal wrote: >>>>>>>>>> On Wed, Aug 01, 2018 at 09:14:50AM -0600, Jens Axboe wrote: >>>>>>>>>>> On 7/31/18 3:34 PM, Anchal Agarwal wrote: >>>>>>>>>>>> Hi folks, >>>>>>>>>>>> >>>>>>>>>>>> This patch modifies commit e34cbd307477a >>>>>>>>>>>> (blk-wbt: add general throttling mechanism) >>>>>>>>>>>> >>>>>>>>>>>> I am currently running a large bare metal instance (i3.metal) >>>>>>>>>>>> on EC2 with 72 cores, 512GB of RAM and NVME drives, with a >>>>>>>>>>>> 4.18 kernel. I have a workload that simulates a database >>>>>>>>>>>> workload and I am running into lockup issues when writeback >>>>>>>>>>>> throttling is enabled,with the hung task detector also >>>>>>>>>>>> kicking in. >>>>>>>>>>>> >>>>>>>>>>>> Crash dumps show that most CPUs (up to 50 of them) are >>>>>>>>>>>> all trying to get the wbt wait queue lock while trying to add >>>>>>>>>>>> themselves to it in __wbt_wait (see stack traces below). >>>>>>>>>>>> >>>>>>>>>>>> [ 0.948118] CPU: 45 PID: 0 Comm: swapper/45 Not tainted 4.14.51-62.38.amzn1.x86_64 #1 >>>>>>>>>>>> [ 0.948119] Hardware name: Amazon EC2 i3.metal/Not Specified, BIOS 1.0 10/16/2017 >>>>>>>>>>>> [ 0.948120] task: ffff883f7878c000 task.stack: ffffc9000c69c000 >>>>>>>>>>>> [ 0.948124] RIP: 0010:native_queued_spin_lock_slowpath+0xf8/0x1a0 >>>>>>>>>>>> [ 0.948125] RSP: 0018:ffff883f7fcc3dc8 EFLAGS: 00000046 >>>>>>>>>>>> [ 0.948126] RAX: 0000000000000000 RBX: ffff887f7709ca68 RCX: ffff883f7fce2a00 >>>>>>>>>>>> [ 0.948128] RDX: 000000000000001c RSI: 0000000000740001 RDI: ffff887f7709ca68 >>>>>>>>>>>> [ 0.948129] RBP: 0000000000000002 R08: 0000000000b80000 R09: 0000000000000000 >>>>>>>>>>>> [ 0.948130] R10: ffff883f7fcc3d78 R11: 000000000de27121 R12: 0000000000000002 >>>>>>>>>>>> [ 0.948131] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000 >>>>>>>>>>>> [ 0.948132] FS: 0000000000000000(0000) GS:ffff883f7fcc0000(0000) knlGS:0000000000000000 >>>>>>>>>>>> [ 0.948134] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 >>>>>>>>>>>> [ 0.948135] CR2: 000000c424c77000 CR3: 0000000002010005 CR4: 00000000003606e0 >>>>>>>>>>>> [ 0.948136] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 >>>>>>>>>>>> [ 0.948137] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 >>>>>>>>>>>> [ 0.948138] Call Trace: >>>>>>>>>>>> [ 0.948139] <IRQ> >>>>>>>>>>>> [ 0.948142] do_raw_spin_lock+0xad/0xc0 >>>>>>>>>>>> [ 0.948145] _raw_spin_lock_irqsave+0x44/0x4b >>>>>>>>>>>> [ 0.948149] ? __wake_up_common_lock+0x53/0x90 >>>>>>>>>>>> [ 0.948150] __wake_up_common_lock+0x53/0x90 >>>>>>>>>>>> [ 0.948155] wbt_done+0x7b/0xa0 >>>>>>>>>>>> [ 0.948158] blk_mq_free_request+0xb7/0x110 >>>>>>>>>>>> [ 0.948161] __blk_mq_complete_request+0xcb/0x140 >>>>>>>>>>>> [ 0.948166] nvme_process_cq+0xce/0x1a0 [nvme] >>>>>>>>>>>> [ 0.948169] nvme_irq+0x23/0x50 [nvme] >>>>>>>>>>>> [ 0.948173] __handle_irq_event_percpu+0x46/0x300 >>>>>>>>>>>> [ 0.948176] handle_irq_event_percpu+0x20/0x50 >>>>>>>>>>>> [ 0.948179] handle_irq_event+0x34/0x60 >>>>>>>>>>>> [ 0.948181] handle_edge_irq+0x77/0x190 >>>>>>>>>>>> [ 0.948185] handle_irq+0xaf/0x120 >>>>>>>>>>>> [ 0.948188] do_IRQ+0x53/0x110 >>>>>>>>>>>> [ 0.948191] common_interrupt+0x87/0x87 >>>>>>>>>>>> [ 0.948192] </IRQ> >>>>>>>>>>>> .... >>>>>>>>>>>> [ 0.311136] CPU: 4 PID: 9737 Comm: run_linux_amd64 Not tainted 4.14.51-62.38.amzn1.x86_64 #1 >>>>>>>>>>>> [ 0.311137] Hardware name: Amazon EC2 i3.metal/Not Specified, BIOS 1.0 10/16/2017 >>>>>>>>>>>> [ 0.311138] task: ffff883f6e6a8000 task.stack: ffffc9000f1ec000 >>>>>>>>>>>> [ 0.311141] RIP: 0010:native_queued_spin_lock_slowpath+0xf5/0x1a0 >>>>>>>>>>>> [ 0.311142] RSP: 0018:ffffc9000f1efa28 EFLAGS: 00000046 >>>>>>>>>>>> [ 0.311144] RAX: 0000000000000000 RBX: ffff887f7709ca68 RCX: ffff883f7f722a00 >>>>>>>>>>>> [ 0.311145] RDX: 0000000000000035 RSI: 0000000000d80001 RDI: ffff887f7709ca68 >>>>>>>>>>>> [ 0.311146] RBP: 0000000000000202 R08: 0000000000140000 R09: 0000000000000000 >>>>>>>>>>>> [ 0.311147] R10: ffffc9000f1ef9d8 R11: 000000001a249fa0 R12: ffff887f7709ca68 >>>>>>>>>>>> [ 0.311148] R13: ffffc9000f1efad0 R14: 0000000000000000 R15: ffff887f7709ca00 >>>>>>>>>>>> [ 0.311149] FS: 000000c423f30090(0000) GS:ffff883f7f700000(0000) knlGS:0000000000000000 >>>>>>>>>>>> [ 0.311150] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 >>>>>>>>>>>> [ 0.311151] CR2: 00007feefcea4000 CR3: 0000007f7016e001 CR4: 00000000003606e0 >>>>>>>>>>>> [ 0.311152] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 >>>>>>>>>>>> [ 0.311153] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 >>>>>>>>>>>> [ 0.311154] Call Trace: >>>>>>>>>>>> [ 0.311157] do_raw_spin_lock+0xad/0xc0 >>>>>>>>>>>> [ 0.311160] _raw_spin_lock_irqsave+0x44/0x4b >>>>>>>>>>>> [ 0.311162] ? prepare_to_wait_exclusive+0x28/0xb0 >>>>>>>>>>>> [ 0.311164] prepare_to_wait_exclusive+0x28/0xb0 >>>>>>>>>>>> [ 0.311167] wbt_wait+0x127/0x330 >>>>>>>>>>>> [ 0.311169] ? finish_wait+0x80/0x80 >>>>>>>>>>>> [ 0.311172] ? generic_make_request+0xda/0x3b0 >>>>>>>>>>>> [ 0.311174] blk_mq_make_request+0xd6/0x7b0 >>>>>>>>>>>> [ 0.311176] ? blk_queue_enter+0x24/0x260 >>>>>>>>>>>> [ 0.311178] ? generic_make_request+0xda/0x3b0 >>>>>>>>>>>> [ 0.311181] generic_make_request+0x10c/0x3b0 >>>>>>>>>>>> [ 0.311183] ? submit_bio+0x5c/0x110 >>>>>>>>>>>> [ 0.311185] submit_bio+0x5c/0x110 >>>>>>>>>>>> [ 0.311197] ? __ext4_journal_stop+0x36/0xa0 [ext4] >>>>>>>>>>>> [ 0.311210] ext4_io_submit+0x48/0x60 [ext4] >>>>>>>>>>>> [ 0.311222] ext4_writepages+0x810/0x11f0 [ext4] >>>>>>>>>>>> [ 0.311229] ? do_writepages+0x3c/0xd0 >>>>>>>>>>>> [ 0.311239] ? ext4_mark_inode_dirty+0x260/0x260 [ext4] >>>>>>>>>>>> [ 0.311240] do_writepages+0x3c/0xd0 >>>>>>>>>>>> [ 0.311243] ? _raw_spin_unlock+0x24/0x30 >>>>>>>>>>>> [ 0.311245] ? wbc_attach_and_unlock_inode+0x165/0x280 >>>>>>>>>>>> [ 0.311248] ? __filemap_fdatawrite_range+0xa3/0xe0 >>>>>>>>>>>> [ 0.311250] __filemap_fdatawrite_range+0xa3/0xe0 >>>>>>>>>>>> [ 0.311253] file_write_and_wait_range+0x34/0x90 >>>>>>>>>>>> [ 0.311264] ext4_sync_file+0x151/0x500 [ext4] >>>>>>>>>>>> [ 0.311267] do_fsync+0x38/0x60 >>>>>>>>>>>> [ 0.311270] SyS_fsync+0xc/0x10 >>>>>>>>>>>> [ 0.311272] do_syscall_64+0x6f/0x170 >>>>>>>>>>>> [ 0.311274] entry_SYSCALL_64_after_hwframe+0x42/0xb7 >>>>>>>>>>>> >>>>>>>>>>>> In the original patch, wbt_done is waking up all the exclusive >>>>>>>>>>>> processes in the wait queue, which can cause a thundering herd >>>>>>>>>>>> if there is a large number of writer threads in the queue. The >>>>>>>>>>>> original intention of the code seems to be to wake up one thread >>>>>>>>>>>> only however, it uses wake_up_all() in __wbt_done(), and then >>>>>>>>>>>> uses the following check in __wbt_wait to have only one thread >>>>>>>>>>>> actually get out of the wait loop: >>>>>>>>>>>> >>>>>>>>>>>> if (waitqueue_active(&rqw->wait) && >>>>>>>>>>>> rqw->wait.head.next != &wait->entry) >>>>>>>>>>>> return false; >>>>>>>>>>>> >>>>>>>>>>>> The problem with this is that the wait entry in wbt_wait is >>>>>>>>>>>> define with DEFINE_WAIT, which uses the autoremove wakeup function. >>>>>>>>>>>> That means that the above check is invalid - the wait entry will >>>>>>>>>>>> have been removed from the queue already by the time we hit the >>>>>>>>>>>> check in the loop. >>>>>>>>>>>> >>>>>>>>>>>> Secondly, auto-removing the wait entries also means that the wait >>>>>>>>>>>> queue essentially gets reordered "randomly" (e.g. threads re-add >>>>>>>>>>>> themselves in the order they got to run after being woken up). >>>>>>>>>>>> Additionally, new requests entering wbt_wait might overtake requests >>>>>>>>>>>> that were queued earlier, because the wait queue will be >>>>>>>>>>>> (temporarily) empty after the wake_up_all, so the waitqueue_active >>>>>>>>>>>> check will not stop them. This can cause certain threads to starve >>>>>>>>>>>> under high load. >>>>>>>>>>>> >>>>>>>>>>>> The fix is to leave the woken up requests in the queue and remove >>>>>>>>>>>> them in finish_wait() once the current thread breaks out of the >>>>>>>>>>>> wait loop in __wbt_wait. This will ensure new requests always >>>>>>>>>>>> end up at the back of the queue, and they won't overtake requests >>>>>>>>>>>> that are already in the wait queue. With that change, the loop >>>>>>>>>>>> in wbt_wait is also in line with many other wait loops in the kernel. >>>>>>>>>>>> Waking up just one thread drastically reduces lock contention, as >>>>>>>>>>>> does moving the wait queue add/remove out of the loop. >>>>>>>>>>>> >>>>>>>>>>>> A significant drop in lockdep's lock contention numbers is seen when >>>>>>>>>>>> running the test application on the patched kernel. >>>>>>>>>>> I like the patch, and a few weeks ago we independently discovered that >>>>>>>>>>> the waitqueue list checking was bogus as well. My only worry is that >>>>>>>>>>> changes like this can be delicate, meaning that it's easy to introduce >>>>>>>>>>> stall conditions. What kind of testing did you push this through? >>>>>>>>>>> >>>>>>>>>>> -- >>>>>>>>>>> Jens Axboe >>>>>>>>>>> >>>>>>>>>> I ran the following tests on both real HW with NVME devices attached >>>>>>>>>> and emulated NVME too: >>>>>>>>>> >>>>>>>>>> 1. The test case I used to reproduce the issue, spawns a bunch of threads >>>>>>>>>> to concurrently read and write files with random size and content. >>>>>>>>>> Files are randomly fsync'd. The implementation is a FIFO queue of files. >>>>>>>>>> When the queue fills the test starts to verify and remove the files. This >>>>>>>>>> test will fail if there's a read, write, or hash check failure. It tests >>>>>>>>>> for file corruption when lots of small files are being read and written >>>>>>>>>> with high concurrency. >>>>>>>>>> >>>>>>>>>> 2. Fio for random writes with a root NVME device of 200GB >>>>>>>>>> >>>>>>>>>> fio --name=randwrite --ioengine=libaio --iodepth=1 --rw=randwrite --bs=4k >>>>>>>>>> --direct=0 --size=10G --numjobs=2 --runtime=60 --group_reporting >>>>>>>>>> >>>>>>>>>> fio --name=randwrite --ioengine=libaio --iodepth=1 --rw=randwrite --bs=4k >>>>>>>>>> --direct=0 --size=5G --numjobs=2 --runtime=30 --fsync=64 --group_reporting >>>>>>>>>> >>>>>>>>>> I did see an improvement in the bandwidth numbers reported on the patched >>>>>>>>>> kernel. >>>>>>>>>> >>>>>>>>>> Do you have any test case/suite in mind that you would suggest me to >>>>>>>>>> run to be sure that patch does not introduce any stall conditions? >>>>>>>>> One thing that is always useful is to run xfstest, do a full run on >>>>>>>>> the device. If that works, then do another full run, this time limiting >>>>>>>>> the queue depth of the SCSI device to 1. If both of those pass, then >>>>>>>>> I'd feel pretty good getting this applied for 4.19. >>>>>>>> Did you get a chance to run this full test? >>>>>>>> >>>>>>>> -- >>>>>>>> Jens Axboe >>>>>>>> >>>>>>>> >>>>>>> Hi Jens, >>>>>>> Yes I did run the tests and was in the process of compiling concrete results >>>>>>> I tested following environments against xfs/auto group >>>>>>> 1. Vanilla 4.18.rc kernel >>>>>>> 2. 4.18 kernel with the blk-wbt patch >>>>>>> 3. 4.18 kernel with the blk-wbt patch + io_queue_depth=2. I >>>>>>> understand you asked for queue depth for SCSI device=1 however, I have NVME >>>>>>> devices in my environment and 2 is the minimum value for io_queue_depth allowed >>>>>>> according to the NVME driver code. The results pretty much look same with no >>>>>>> stalls or exceptional failures. >>>>>>> xfs/auto ran 296 odd tests with 3 failures and 130 something "no runs". >>>>>>> Remaining tests passed. "Skipped tests" were mostly due to missing features >>>>>>> (eg: reflink support on scratch filesystem) >>>>>>> The failures were consistent across runs on 3 different environments. >>>>>>> I am also running full test suite but it is taking long time as I am >>>>>>> hitting kernel BUG in xfs code in some generic tests. This BUG is not >>>>>>> related to the patch and I see them in vanilla kernel too. I am in >>>>>>> the process of excluding these kind of tests as they come and >>>>>>> re-run the suite however, this proces is time taking. >>>>>>> Do you have any specific tests in mind that you would like me >>>>>>> to run apart from what I have already tested above? >>>>>> Thanks, I think that looks good. I'll get your patch applied for >>>>>> 4.19. >>>>>> >>>>>> -- >>>>>> Jens Axboe >>>>>> >>>>>> >>>>> Hi Jens, >>>>> Thanks for accepting this. There is one small issue, I don't find any emails >>>>> send by me on the lkml mailing list. I am not sure why it didn't land there, >>>>> all I can see is your responses. Do you want one of us to resend the patch >>>>> or will you be able to do it? >>>> That's odd, are you getting rejections on your emails? For reference, the >>>> patch is here: >>>> >>>> http://git.kernel.dk/cgit/linux-block/commit/?h=for-4.19/block&id=2887e41b910bb14fd847cf01ab7a5993db989d88 >>> One issue with this, as far as I can tell. Right now we've switched to >>> waking one task at the time, which is obviously more efficient. But if >>> we do that with exclusive waits, then we have to ensure that this task >>> makes progress. If we wake up a task, and then fail to get a queueing >>> token, then we'll go back to sleep. We need to ensure that someone makes >>> forward progress at this point. There are two ways I can see that >>> happening: >>> >>> 1) The task woken _always_ gets to queue an IO >>> 2) If the task woken is NOT allowed to queue an IO, then it must select >>> a new task to wake up. That new task is then subjected to rule 1 or 2 >>> as well. >>> >>> For #1, it could be as simple as: >>> >>> if (slept || !rwb_enabled(rwb)) { >>> atomic_inc(&rqw->inflight); >>> break; >>> } >>> >>> but this obviously won't always be fair. Might be good enough however, >>> instead of having to eg replace the generic wait queues with a priority >>> list/queue. >>> >>> Note that this isn't an entirely new issue, it's just so much easier to >>> hit with the single wakeups. >>> >> Hi Jens, >> >> What is the scenario that you see under which the woken up task does not >> get to run? > > That scenario is pretty easy to hit - let's say the next in line task > has a queue limit of 1, and we currently have 4 pending. Task gets > woken, goes back to sleep. Which should be totally fine. At some point > we'll get below the limit, and allow the task to proceed. This will > ensure forward progress. > >> The theory behind leaving the task on the wait queue is that the >> waitqueue_active check in wbt_wait prevents new tasks from taking up a >> slot in the queue (e.g. incrementing inflight). So, there should not be >> a way for inflight to be incremented between the time the wake_up is >> done and the task at the head of the wait queue runs. That's the idea >> anyway :-) If we missed something, let us know. > > And that's a fine theory, I think it's a good improvement (and how it > should have worked). I'm struggling to see where the issue is. Perhaps > it's related to the wq active check. With fewer wakeups, we're more > likely to hit a race there. > > I'll poke at it... Trying something like this: http://git.kernel.dk/cgit/linux-block/log/?h=for-4.19/wbt -- Jens Axboe
