* [PATCH] md/raid5: preserve STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list @ 2017-08-28 12:01 Dennis Yang 2017-09-01 5:38 ` Shaohua Li 0 siblings, 1 reply; 5+ messages in thread From: Dennis Yang @ 2017-08-28 12:01 UTC (permalink / raw) Cc: Dennis Yang, Shaohua Li, linux-raid, linux-kernel break_stripe_batch_list() did not preserve STRIPE_ON_UNPLUG_LIST which is set when a stripe_head gets queued to the stripe_head list maintained by raid5_plug_cb and waiting for releasing after blk_unplug(). In release_stripe_plug(), if a stripe_head has its STRIPE_ON_UNPLUG_LIST set, it indicates that this stripe_head is already in the raid5_plug_cb list and release_stripe() would be called instead to drop a reference count. Otherwise, the STRIPE_ON_UNPLUG_LIST bit would be set for this stripe_head and it will get queued into the raid5_plug_cb list. Without preserving STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list(), a stripe_head could be re-added to the raid5_plug_cb list while it is currently on that list and waiting to be released. This would mess up the raid5_plug_cb and leads to soft/hard lockup in raid5_unplug() or kernel crash. Signed-off-by: Dennis Yang <dennisyang@qnap.com> --- drivers/md/raid5.c | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/drivers/md/raid5.c b/drivers/md/raid5.c index e92dd2d..faf3cfd 100644 --- a/drivers/md/raid5.c +++ b/drivers/md/raid5.c @@ -4611,7 +4611,8 @@ static void break_stripe_batch_list(struct stripe_head *head_sh, set_mask_bits(&sh->state, ~(STRIPE_EXPAND_SYNC_FLAGS | (1 << STRIPE_PREREAD_ACTIVE) | - (1 << STRIPE_DEGRADED)), + (1 << STRIPE_DEGRADED) | + (1 << STRIPE_ON_UNPLUG_LIST)), head_sh->state & (1 << STRIPE_INSYNC)); sh->check_state = head_sh->check_state; -- 1.9.1 ^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH] md/raid5: preserve STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list 2017-08-28 12:01 [PATCH] md/raid5: preserve STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list Dennis Yang @ 2017-09-01 5:38 ` Shaohua Li 2017-09-01 9:26 ` Dennis Yang 0 siblings, 1 reply; 5+ messages in thread From: Shaohua Li @ 2017-09-01 5:38 UTC (permalink / raw) To: Dennis Yang; +Cc: linux-raid, linux-kernel On Mon, Aug 28, 2017 at 08:01:59PM +0800, Dennis Yang wrote: > break_stripe_batch_list() did not preserve STRIPE_ON_UNPLUG_LIST which is > set when a stripe_head gets queued to the stripe_head list maintained by > raid5_plug_cb and waiting for releasing after blk_unplug(). > > In release_stripe_plug(), if a stripe_head has its STRIPE_ON_UNPLUG_LIST > set, it indicates that this stripe_head is already in the raid5_plug_cb > list and release_stripe() would be called instead to drop a reference > count. Otherwise, the STRIPE_ON_UNPLUG_LIST bit would be set for this > stripe_head and it will get queued into the raid5_plug_cb list. > > Without preserving STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list(), > a stripe_head could be re-added to the raid5_plug_cb list while it is > currently on that list and waiting to be released. This would mess up > the raid5_plug_cb and leads to soft/hard lockup in raid5_unplug() or > kernel crash. Did you observe this? From my understanding, this is impossible. If a stripe is in batch list (that's why we have break_stripe_batch_list), add_stripe_bio will bail out (because sh->batch_head != NULL), so the stripe is never added into plug list, hence has the STRIPE_ON_UNPLUG_LIST bit set. Am I missing anything? Thanks, Shaohua > Signed-off-by: Dennis Yang <dennisyang@qnap.com> > --- > drivers/md/raid5.c | 3 ++- > 1 file changed, 2 insertions(+), 1 deletion(-) > > diff --git a/drivers/md/raid5.c b/drivers/md/raid5.c > index e92dd2d..faf3cfd 100644 > --- a/drivers/md/raid5.c > +++ b/drivers/md/raid5.c > @@ -4611,7 +4611,8 @@ static void break_stripe_batch_list(struct stripe_head *head_sh, > > set_mask_bits(&sh->state, ~(STRIPE_EXPAND_SYNC_FLAGS | > (1 << STRIPE_PREREAD_ACTIVE) | > - (1 << STRIPE_DEGRADED)), > + (1 << STRIPE_DEGRADED) | > + (1 << STRIPE_ON_UNPLUG_LIST)), > head_sh->state & (1 << STRIPE_INSYNC)); > > sh->check_state = head_sh->check_state; > -- > 1.9.1 > ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] md/raid5: preserve STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list 2017-09-01 5:38 ` Shaohua Li @ 2017-09-01 9:26 ` Dennis Yang 2017-09-05 19:24 ` Shaohua Li 0 siblings, 1 reply; 5+ messages in thread From: Dennis Yang @ 2017-09-01 9:26 UTC (permalink / raw) To: shli; +Cc: linux-raid, linux-kernel, Dennis Yang >On Mon, Aug 28, 2017 at 08:01:59PM +0800, Dennis Yang wrote: >> break_stripe_batch_list() did not preserve STRIPE_ON_UNPLUG_LIST which is >> set when a stripe_head gets queued to the stripe_head list maintained by >> raid5_plug_cb and waiting for releasing after blk_unplug(). >> >> In release_stripe_plug(), if a stripe_head has its STRIPE_ON_UNPLUG_LIST >> set, it indicates that this stripe_head is already in the raid5_plug_cb >> list and release_stripe() would be called instead to drop a reference >> count. Otherwise, the STRIPE_ON_UNPLUG_LIST bit would be set for this >> stripe_head and it will get queued into the raid5_plug_cb list. >> >> Without preserving STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list(), >> a stripe_head could be re-added to the raid5_plug_cb list while it is >> currently on that list and waiting to be released. This would mess up >> the raid5_plug_cb and leads to soft/hard lockup in raid5_unplug() or >> kernel crash. > >Did you observe this? From my understanding, this is impossible. If a stripe is >in batch list (that's why we have break_stripe_batch_list), add_stripe_bio will >bail out (because sh->batch_head != NULL), so the stripe is never added into >plug list, hence has the STRIPE_ON_UNPLUG_LIST bit set. Am I missing anything? > >Thanks, >Shaohua It is hard to reproduce. Our storage exports 4 iscsi LUNs which are built on top of a dm-thin pool with 8 x SSD RAID6. Each two of these iscsi LUNs are connected to a windows server which runs 4 fio jobs with 16 threads and iodepth = 16. In this setup, we can get the following call trace after couples of hours. The stack dump basically shows that the raid5_unplug is holding the conf->device_lock for a very long time. After adding some debug traces, we can confirm that the raid5_plug_cb->list is corrupted which sometimes leads to infinite loop in raid5_unplug. I didn't notice that add_stripe_bio will bail out if the stripe_head is in someone's batch list, but I am wondering if the following scenario will still happen. If a stripe_head A is added to another stripe_head B's batch list, in this case A will have its batch_head != NULL and be added into the plug list. After that, stripe_head B gets handled and called break_stripe_batch_list() to reset all the batched stripe_head(including A which is still on the plug list)'s state and reset their batch_head to NULL. Before the plug list gets processed, if there is another write request comes in and get stripe_head A, A will have its batch_head == NULL (cleared by calling break_stripe_batch_list() on B) and be added to plug list once again. Since we have the environment which can reproduce this issue in 6 hours, if there is anything we can do to help resolve this issue, we are more than willing to help. Thanks, Dennis [ 4481.493998] BUG: spinlock lockup suspected on CPU#10, md1_raid6/5497 [ 4481.501109] lock: 0xffff88102b242888, .magic: dead4ead, .owner: kworker/u24:2/22322, .owner_cpu: 0 [ 4481.511231] CPU: 10 PID: 5497 Comm: md1_raid6 Tainted: P W O 4.2.8 #7 [ 4481.519504] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 [ 4481.529429] ffff88102b242888 ffff881014967c78 ffffffff81c933b6 0000000000000007 [ 4481.537739] ffff8805c9720a00 ffff881014967c98 ffffffff810d2c20 ffff88102b242888 [ 4481.546048] 0000000082d0f7c8 ffff881014967cc8 ffffffff810d2d9b ffff88102b242888 [ 4481.554357] Call Trace: [ 4481.557093] [<ffffffff81c933b6>] dump_stack+0x4c/0x65 [ 4481.562840] [<ffffffff810d2c20>] spin_dump+0x80/0xd0 [ 4481.568489] [<ffffffff810d2d9b>] do_raw_spin_lock+0x9b/0x120 [ 4481.574916] [<ffffffff81ca14d1>] _raw_spin_lock_irq+0x41/0x50 [ 4481.581443] [<ffffffff816d2204>] ? raid5d+0x64/0x790 [ 4481.587091] [<ffffffff816d2204>] raid5d+0x64/0x790 [ 4481.592546] [<ffffffff810c35c6>] ? finish_wait+0x46/0x80 [ 4481.598583] [<ffffffff810c35e8>] ? finish_wait+0x68/0x80 [ 4481.604621] [<ffffffff816d8d2e>] md_thread+0x13e/0x150 [ 4481.610464] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 [ 4481.616405] [<ffffffff816d8bf0>] ? find_pers+0x80/0x80 [ 4481.622249] [<ffffffff8109eed5>] kthread+0x105/0x120 [ 4481.627899] [<ffffffff8109edd0>] ? kthread_create_on_node+0x220/0x220 [ 4481.635201] [<ffffffff81ca218f>] ret_from_fork+0x3f/0x70 [ 4481.641239] [<ffffffff8109edd0>] ? kthread_create_on_node+0x220/0x220 [ 4481.654638] NMI backtrace for cpu 0 [ 4481.658536] CPU: 0 PID: 22322 Comm: kworker/u24:2 Tainted: P W O 4.2.8 #7 [ 4481.667198] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 [ 4481.677124] Workqueue: writeback wb_workfn (flush-252:15) [ 4481.683160] task: ffff8805c9720a00 ti: ffff8805c84f8000 task.ti: ffff8805c84f8000 [ 4481.691531] RIP: 0010:[<ffffffff816cd9f1>] [<ffffffff816cd9f1>] raid5_unplug+0x71/0x270 [ 4481.700582] RSP: 0018:ffff8805c84fb938 EFLAGS: 00000046 [ 4481.706521] RAX: ffff8805cd2ce258 RBX: ffff881038557280 RCX: ffff8805cd2ce258 [ 4481.714502] RDX: ffff8805cd2ce258 RSI: ffff8805cd2ce248 RDI: ffff88102b242000 [ 4481.722483] RBP: ffff8805c84fb978 R08: ffffffff81e0a1c0 R09: 0000000000000000 [ 4481.730464] R10: 0000000000000000 R11: 00000000071775d0 R12: 00000000b921e53c [ 4481.738445] R13: ffff88102b242000 R14: ffff8810385572a0 R15: ffff88102feec000 [ 4481.746427] FS: 0000000000000000(0000) GS:ffff88107fc00000(0000) knlGS:0000000000000000 [ 4481.755477] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 4481.761904] CR2: 00007fb7bf2d2000 CR3: 0000000fff8df000 CR4: 00000000003406f0 [ 4481.769886] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 4481.777868] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 4481.785848] Stack: [ 4481.788094] 00000000f835a020 ffff88102b242888 ffff8805c84fbb48 ffff8805c84fb9a8 [ 4481.796366] 0000000000000000 ffff8805c84fba28 ffff8805c84fba48 ffff8805c84fb998 [ 4481.804640] ffff8805c84fb9e8 ffffffff81463c8b ffff8805c84fb9d8 ffffffff81461bb2 [ 4481.812912] Call Trace: [ 4481.815644] [<ffffffff81463c8b>] blk_flush_plug_list+0x9b/0x230 [ 4481.822361] [<ffffffff81461bb2>] ? submit_bio+0x62/0x150 [ 4481.828398] [<ffffffff81464364>] blk_finish_plug+0x24/0x40 [ 4481.834628] [<ffffffff812292c3>] mpage_writepages+0x73/0x90 [ 4481.840956] [<ffffffff81222f90>] ? I_BDEV+0x10/0x10 [ 4481.846506] [<ffffffff81225380>] qnap_blkdev_writepages+0x10/0x20 [ 4481.853418] [<ffffffff81188af9>] do_writepages+0x59/0x70 [ 4481.859455] [<ffffffff81213874>] __writeback_single_inode+0x74/0xa50 [ 4481.866658] [<ffffffff81214a41>] writeback_sb_inodes+0x2f1/0x680 [ 4481.873472] [<ffffffff81214e54>] __writeback_inodes_wb+0x84/0xb0 [ 4481.880287] [<ffffffff812151a9>] wb_writeback+0x329/0x6e0 [ 4482.914006] NMI backtrace for cpu 5 [ 4482.917906] CPU: 5 PID: 26333 Comm: kworker/u24:5 Tainted: P W O 4.2.8 #7 [ 4482.926567] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 [ 4482.936492] Workqueue: writeback wb_workfn (flush-252:14) [ 4482.942529] task: ffff8805c7a74340 ti: ffff8805c6228000 task.ti: ffff8805c6228000 [ 4482.950898] RIP: 0010:[<ffffffff8149cfd7>] [<ffffffff8149cfd7>] delay_tsc+0x17/0x70 [ 4482.959558] RSP: 0018:ffff8805c622b368 EFLAGS: 00000082 [ 4482.965498] RAX: 00000000dc0ef28f RBX: ffff88102b242888 RCX: 00000000dc0ef259 [ 4482.973479] RDX: 0000000000003c68 RSI: 0000000000000005 RDI: 0000000000000001 [ 4482.981460] RBP: ffff8805c622b368 R08: 0000000000000001 R09: 0000000000000001 [ 4482.989441] R10: 0000000000000000 R11: 0000000000000007 R12: 00000000763815f7 [ 4482.997422] R13: 0000000000000001 R14: 0000000082d0f7c8 R15: ffff88102feec000 [ 4483.005403] FS: 0000000000000000(0000) GS:ffff88107fca0000(0000) knlGS:0000000000000000 [ 4483.014459] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 4483.020876] CR2: 00007f54d805a030 CR3: 0000001006c20000 CR4: 00000000003406e0 [ 4483.028858] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 4483.036840] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 4483.044822] Stack: [ 4483.047069] ffff8805c622b378 ffffffff8149cf2a ffff8805c622b3a8 ffffffff810d2d87 [ 4483.055341] ffff88102b242888 0000000000000000 ffff88102b242000 ffff881007d702a0 [ 4483.063613] ffff8805c622b3d8 ffffffff81ca14d1 ffffffff816cd9ca 0000000000000000 [ 4483.071885] Call Trace: [ 4483.074617] [<ffffffff8149cf2a>] __delay+0xa/0x10 [ 4483.079973] [<ffffffff810d2d87>] do_raw_spin_lock+0x87/0x120 [ 4483.086399] [<ffffffff81ca14d1>] _raw_spin_lock_irq+0x41/0x50 [ 4483.092920] [<ffffffff816cd9ca>] ? raid5_unplug+0x4a/0x270 [ 4483.099151] [<ffffffff816cd9ca>] raid5_unplug+0x4a/0x270 [ 4483.105188] [<ffffffff81463c8b>] blk_flush_plug_list+0x9b/0x230 [ 4483.111907] [<ffffffff81c9bf9d>] schedule+0x6d/0x90 [ 4483.117459] [<ffffffff816c9910>] __get_active_stripe.constprop.61+0x750/0x970 [ 4483.125539] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 [ 4483.131480] [<ffffffff816c9d2a>] make_request+0x1fa/0xe30 [ 4483.137616] [<ffffffff816ddc8e>] ? md_make_request+0x1fe/0x4b0 [ 4483.144238] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 [ 4483.150179] [<ffffffff816ddc52>] ? md_make_request+0x1c2/0x4b0 [ 4483.156800] [<ffffffff816ddc8e>] md_make_request+0x1fe/0x4b0 [ 4483.163227] [<ffffffff816ddade>] ? md_make_request+0x4e/0x4b0 [ 4483.169750] [<ffffffff816edd43>] ? dm_make_request+0x73/0x110 [ 4483.176273] [<ffffffff81461b0e>] generic_make_request+0xce/0x110 ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] md/raid5: preserve STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list 2017-09-01 9:26 ` Dennis Yang @ 2017-09-05 19:24 ` Shaohua Li 2017-09-06 3:17 ` Dennis Yang 0 siblings, 1 reply; 5+ messages in thread From: Shaohua Li @ 2017-09-05 19:24 UTC (permalink / raw) To: Dennis Yang; +Cc: linux-raid, linux-kernel On Fri, Sep 01, 2017 at 05:26:48PM +0800, Dennis Yang wrote: > >On Mon, Aug 28, 2017 at 08:01:59PM +0800, Dennis Yang wrote: > >> break_stripe_batch_list() did not preserve STRIPE_ON_UNPLUG_LIST which is > >> set when a stripe_head gets queued to the stripe_head list maintained by > >> raid5_plug_cb and waiting for releasing after blk_unplug(). > >> > >> In release_stripe_plug(), if a stripe_head has its STRIPE_ON_UNPLUG_LIST > >> set, it indicates that this stripe_head is already in the raid5_plug_cb > >> list and release_stripe() would be called instead to drop a reference > >> count. Otherwise, the STRIPE_ON_UNPLUG_LIST bit would be set for this > >> stripe_head and it will get queued into the raid5_plug_cb list. > >> > >> Without preserving STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list(), > >> a stripe_head could be re-added to the raid5_plug_cb list while it is > >> currently on that list and waiting to be released. This would mess up > >> the raid5_plug_cb and leads to soft/hard lockup in raid5_unplug() or > >> kernel crash. > > > >Did you observe this? From my understanding, this is impossible. If a stripe is > >in batch list (that's why we have break_stripe_batch_list), add_stripe_bio will > >bail out (because sh->batch_head != NULL), so the stripe is never added into > >plug list, hence has the STRIPE_ON_UNPLUG_LIST bit set. Am I missing anything? > > > >Thanks, > >Shaohua > > It is hard to reproduce. Our storage exports 4 iscsi LUNs which are built on > top of a dm-thin pool with 8 x SSD RAID6. Each two of these iscsi LUNs are > connected to a windows server which runs 4 fio jobs with 16 threads and > iodepth = 16. In this setup, we can get the following call trace after couples > of hours. The stack dump basically shows that the raid5_unplug is holding the > conf->device_lock for a very long time. After adding some debug traces, we can > confirm that the raid5_plug_cb->list is corrupted which sometimes leads to > infinite loop in raid5_unplug. > > I didn't notice that add_stripe_bio will bail out if the stripe_head is in > someone's batch list, but I am wondering if the following scenario will still > happen. If a stripe_head A is added to another stripe_head B's batch list, in > this case A will have its batch_head != NULL and be added into the plug list. > After that, stripe_head B gets handled and called break_stripe_batch_list() to > reset all the batched stripe_head(including A which is still on the plug list)'s > state and reset their batch_head to NULL. Before the plug list gets processed, > if there is another write request comes in and get stripe_head A, A will have > its batch_head == NULL (cleared by calling break_stripe_batch_list() on B) and > be added to plug list once again. > > Since we have the environment which can reproduce this issue in 6 hours, if > there is anything we can do to help resolve this issue, we are more than > willing to help. yes, I think you are right. If the stripe is on one thread's plug list, the thread doesn't do unplug till the stripe is handled (because it's part of a batch), we will have the stripe in plug list but not have the bit set. Can you resend the patch with description what happens? BTW, does the patch fix your issue? Thanks, Shaohua > > Thanks, > Dennis > > [ 4481.493998] BUG: spinlock lockup suspected on CPU#10, md1_raid6/5497 > [ 4481.501109] lock: 0xffff88102b242888, .magic: dead4ead, .owner: kworker/u24:2/22322, .owner_cpu: 0 > [ 4481.511231] CPU: 10 PID: 5497 Comm: md1_raid6 Tainted: P W O 4.2.8 #7 > [ 4481.519504] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 > [ 4481.529429] ffff88102b242888 ffff881014967c78 ffffffff81c933b6 0000000000000007 > [ 4481.537739] ffff8805c9720a00 ffff881014967c98 ffffffff810d2c20 ffff88102b242888 > [ 4481.546048] 0000000082d0f7c8 ffff881014967cc8 ffffffff810d2d9b ffff88102b242888 > [ 4481.554357] Call Trace: > [ 4481.557093] [<ffffffff81c933b6>] dump_stack+0x4c/0x65 > [ 4481.562840] [<ffffffff810d2c20>] spin_dump+0x80/0xd0 > [ 4481.568489] [<ffffffff810d2d9b>] do_raw_spin_lock+0x9b/0x120 > [ 4481.574916] [<ffffffff81ca14d1>] _raw_spin_lock_irq+0x41/0x50 > [ 4481.581443] [<ffffffff816d2204>] ? raid5d+0x64/0x790 > [ 4481.587091] [<ffffffff816d2204>] raid5d+0x64/0x790 > [ 4481.592546] [<ffffffff810c35c6>] ? finish_wait+0x46/0x80 > [ 4481.598583] [<ffffffff810c35e8>] ? finish_wait+0x68/0x80 > [ 4481.604621] [<ffffffff816d8d2e>] md_thread+0x13e/0x150 > [ 4481.610464] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 > [ 4481.616405] [<ffffffff816d8bf0>] ? find_pers+0x80/0x80 > [ 4481.622249] [<ffffffff8109eed5>] kthread+0x105/0x120 > [ 4481.627899] [<ffffffff8109edd0>] ? kthread_create_on_node+0x220/0x220 > [ 4481.635201] [<ffffffff81ca218f>] ret_from_fork+0x3f/0x70 > [ 4481.641239] [<ffffffff8109edd0>] ? kthread_create_on_node+0x220/0x220 > [ 4481.654638] NMI backtrace for cpu 0 > [ 4481.658536] CPU: 0 PID: 22322 Comm: kworker/u24:2 Tainted: P W O 4.2.8 #7 > [ 4481.667198] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 > [ 4481.677124] Workqueue: writeback wb_workfn (flush-252:15) > [ 4481.683160] task: ffff8805c9720a00 ti: ffff8805c84f8000 task.ti: ffff8805c84f8000 > [ 4481.691531] RIP: 0010:[<ffffffff816cd9f1>] [<ffffffff816cd9f1>] raid5_unplug+0x71/0x270 > [ 4481.700582] RSP: 0018:ffff8805c84fb938 EFLAGS: 00000046 > [ 4481.706521] RAX: ffff8805cd2ce258 RBX: ffff881038557280 RCX: ffff8805cd2ce258 > [ 4481.714502] RDX: ffff8805cd2ce258 RSI: ffff8805cd2ce248 RDI: ffff88102b242000 > [ 4481.722483] RBP: ffff8805c84fb978 R08: ffffffff81e0a1c0 R09: 0000000000000000 > [ 4481.730464] R10: 0000000000000000 R11: 00000000071775d0 R12: 00000000b921e53c > [ 4481.738445] R13: ffff88102b242000 R14: ffff8810385572a0 R15: ffff88102feec000 > [ 4481.746427] FS: 0000000000000000(0000) GS:ffff88107fc00000(0000) knlGS:0000000000000000 > [ 4481.755477] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 4481.761904] CR2: 00007fb7bf2d2000 CR3: 0000000fff8df000 CR4: 00000000003406f0 > [ 4481.769886] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 4481.777868] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 > [ 4481.785848] Stack: > [ 4481.788094] 00000000f835a020 ffff88102b242888 ffff8805c84fbb48 ffff8805c84fb9a8 > [ 4481.796366] 0000000000000000 ffff8805c84fba28 ffff8805c84fba48 ffff8805c84fb998 > [ 4481.804640] ffff8805c84fb9e8 ffffffff81463c8b ffff8805c84fb9d8 ffffffff81461bb2 > [ 4481.812912] Call Trace: > [ 4481.815644] [<ffffffff81463c8b>] blk_flush_plug_list+0x9b/0x230 > [ 4481.822361] [<ffffffff81461bb2>] ? submit_bio+0x62/0x150 > [ 4481.828398] [<ffffffff81464364>] blk_finish_plug+0x24/0x40 > [ 4481.834628] [<ffffffff812292c3>] mpage_writepages+0x73/0x90 > [ 4481.840956] [<ffffffff81222f90>] ? I_BDEV+0x10/0x10 > [ 4481.846506] [<ffffffff81225380>] qnap_blkdev_writepages+0x10/0x20 > [ 4481.853418] [<ffffffff81188af9>] do_writepages+0x59/0x70 > [ 4481.859455] [<ffffffff81213874>] __writeback_single_inode+0x74/0xa50 > [ 4481.866658] [<ffffffff81214a41>] writeback_sb_inodes+0x2f1/0x680 > [ 4481.873472] [<ffffffff81214e54>] __writeback_inodes_wb+0x84/0xb0 > [ 4481.880287] [<ffffffff812151a9>] wb_writeback+0x329/0x6e0 > [ 4482.914006] NMI backtrace for cpu 5 > [ 4482.917906] CPU: 5 PID: 26333 Comm: kworker/u24:5 Tainted: P W O 4.2.8 #7 > [ 4482.926567] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 > [ 4482.936492] Workqueue: writeback wb_workfn (flush-252:14) > [ 4482.942529] task: ffff8805c7a74340 ti: ffff8805c6228000 task.ti: ffff8805c6228000 > [ 4482.950898] RIP: 0010:[<ffffffff8149cfd7>] [<ffffffff8149cfd7>] delay_tsc+0x17/0x70 > [ 4482.959558] RSP: 0018:ffff8805c622b368 EFLAGS: 00000082 > [ 4482.965498] RAX: 00000000dc0ef28f RBX: ffff88102b242888 RCX: 00000000dc0ef259 > [ 4482.973479] RDX: 0000000000003c68 RSI: 0000000000000005 RDI: 0000000000000001 > [ 4482.981460] RBP: ffff8805c622b368 R08: 0000000000000001 R09: 0000000000000001 > [ 4482.989441] R10: 0000000000000000 R11: 0000000000000007 R12: 00000000763815f7 > [ 4482.997422] R13: 0000000000000001 R14: 0000000082d0f7c8 R15: ffff88102feec000 > [ 4483.005403] FS: 0000000000000000(0000) GS:ffff88107fca0000(0000) knlGS:0000000000000000 > [ 4483.014459] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 4483.020876] CR2: 00007f54d805a030 CR3: 0000001006c20000 CR4: 00000000003406e0 > [ 4483.028858] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 4483.036840] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 > [ 4483.044822] Stack: > [ 4483.047069] ffff8805c622b378 ffffffff8149cf2a ffff8805c622b3a8 ffffffff810d2d87 > [ 4483.055341] ffff88102b242888 0000000000000000 ffff88102b242000 ffff881007d702a0 > [ 4483.063613] ffff8805c622b3d8 ffffffff81ca14d1 ffffffff816cd9ca 0000000000000000 > [ 4483.071885] Call Trace: > [ 4483.074617] [<ffffffff8149cf2a>] __delay+0xa/0x10 > [ 4483.079973] [<ffffffff810d2d87>] do_raw_spin_lock+0x87/0x120 > [ 4483.086399] [<ffffffff81ca14d1>] _raw_spin_lock_irq+0x41/0x50 > [ 4483.092920] [<ffffffff816cd9ca>] ? raid5_unplug+0x4a/0x270 > [ 4483.099151] [<ffffffff816cd9ca>] raid5_unplug+0x4a/0x270 > [ 4483.105188] [<ffffffff81463c8b>] blk_flush_plug_list+0x9b/0x230 > [ 4483.111907] [<ffffffff81c9bf9d>] schedule+0x6d/0x90 > [ 4483.117459] [<ffffffff816c9910>] __get_active_stripe.constprop.61+0x750/0x970 > [ 4483.125539] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 > [ 4483.131480] [<ffffffff816c9d2a>] make_request+0x1fa/0xe30 > [ 4483.137616] [<ffffffff816ddc8e>] ? md_make_request+0x1fe/0x4b0 > [ 4483.144238] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 > [ 4483.150179] [<ffffffff816ddc52>] ? md_make_request+0x1c2/0x4b0 > [ 4483.156800] [<ffffffff816ddc8e>] md_make_request+0x1fe/0x4b0 > [ 4483.163227] [<ffffffff816ddade>] ? md_make_request+0x4e/0x4b0 > [ 4483.169750] [<ffffffff816edd43>] ? dm_make_request+0x73/0x110 > [ 4483.176273] [<ffffffff81461b0e>] generic_make_request+0xce/0x110 > > ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] md/raid5: preserve STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list 2017-09-05 19:24 ` Shaohua Li @ 2017-09-06 3:17 ` Dennis Yang 0 siblings, 0 replies; 5+ messages in thread From: Dennis Yang @ 2017-09-06 3:17 UTC (permalink / raw) To: shli; +Cc: linux-raid, linux-kernel, Dennis Yang > On Fri, Sep 01, 2017 at 05:26:48PM +0800, Dennis Yang wrote: > > >On Mon, Aug 28, 2017 at 08:01:59PM +0800, Dennis Yang wrote: > > >> break_stripe_batch_list() did not preserve STRIPE_ON_UNPLUG_LIST which is > > >> set when a stripe_head gets queued to the stripe_head list maintained by > > >> raid5_plug_cb and waiting for releasing after blk_unplug(). > > >> > > >> In release_stripe_plug(), if a stripe_head has its STRIPE_ON_UNPLUG_LIST > > >> set, it indicates that this stripe_head is already in the raid5_plug_cb > > >> list and release_stripe() would be called instead to drop a reference > > >> count. Otherwise, the STRIPE_ON_UNPLUG_LIST bit would be set for this > > >> stripe_head and it will get queued into the raid5_plug_cb list. > > >> > > >> Without preserving STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list(), > > >> a stripe_head could be re-added to the raid5_plug_cb list while it is > > >> currently on that list and waiting to be released. This would mess up > > >> the raid5_plug_cb and leads to soft/hard lockup in raid5_unplug() or > > >> kernel crash. > > > > > >Did you observe this? From my understanding, this is impossible. If a stripe is > > >in batch list (that's why we have break_stripe_batch_list), add_stripe_bio will > > >bail out (because sh->batch_head != NULL), so the stripe is never added into > > >plug list, hence has the STRIPE_ON_UNPLUG_LIST bit set. Am I missing anything? > > > > > >Thanks, > > >Shaohua > > > > It is hard to reproduce. Our storage exports 4 iscsi LUNs which are built on > > top of a dm-thin pool with 8 x SSD RAID6. Each two of these iscsi LUNs are > > connected to a windows server which runs 4 fio jobs with 16 threads and > > iodepth = 16. In this setup, we can get the following call trace after couples > > of hours. The stack dump basically shows that the raid5_unplug is holding the > > conf->device_lock for a very long time. After adding some debug traces, we can > > confirm that the raid5_plug_cb->list is corrupted which sometimes leads to > > infinite loop in raid5_unplug. > > > > I didn't notice that add_stripe_bio will bail out if the stripe_head is in > > someone's batch list, but I am wondering if the following scenario will still > > happen. If a stripe_head A is added to another stripe_head B's batch list, in > > this case A will have its batch_head != NULL and be added into the plug list. > > After that, stripe_head B gets handled and called break_stripe_batch_list() to > > reset all the batched stripe_head(including A which is still on the plug list)'s > > state and reset their batch_head to NULL. Before the plug list gets processed, > > if there is another write request comes in and get stripe_head A, A will have > > its batch_head == NULL (cleared by calling break_stripe_batch_list() on B) and > > be added to plug list once again. > > > > Since we have the environment which can reproduce this issue in 6 hours, if > > there is anything we can do to help resolve this issue, we are more than > > willing to help. > > yes, I think you are right. If the stripe is on one thread's plug list, the > thread doesn't do unplug till the stripe is handled (because it's part of a > batch), we will have the stripe in plug list but not have the bit set. Can you > resend the patch with description what happens? BTW, does the patch fix your > issue? > > Thanks, > Shaohua Sure, I will resend a patch to you with updated commit message. We have already run the same stress test on the same environment for 6 days without any error. Since the test cannot run more than 6 hours before this patch, I think it does fix my issue. Thanks, Dennis > > > > Thanks, > > Dennis > > > > [ 4481.493998] BUG: spinlock lockup suspected on CPU#10, md1_raid6/5497 > > [ 4481.501109] lock: 0xffff88102b242888, .magic: dead4ead, .owner: kworker/u24:2/22322, .owner_cpu: 0 > > [ 4481.511231] CPU: 10 PID: 5497 Comm: md1_raid6 Tainted: P W O 4.2.8 #7 > > [ 4481.519504] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 > > [ 4481.529429] ffff88102b242888 ffff881014967c78 ffffffff81c933b6 0000000000000007 > > [ 4481.537739] ffff8805c9720a00 ffff881014967c98 ffffffff810d2c20 ffff88102b242888 > > [ 4481.546048] 0000000082d0f7c8 ffff881014967cc8 ffffffff810d2d9b ffff88102b242888 > > [ 4481.554357] Call Trace: > > [ 4481.557093] [<ffffffff81c933b6>] dump_stack+0x4c/0x65 > > [ 4481.562840] [<ffffffff810d2c20>] spin_dump+0x80/0xd0 > > [ 4481.568489] [<ffffffff810d2d9b>] do_raw_spin_lock+0x9b/0x120 > > [ 4481.574916] [<ffffffff81ca14d1>] _raw_spin_lock_irq+0x41/0x50 > > [ 4481.581443] [<ffffffff816d2204>] ? raid5d+0x64/0x790 > > [ 4481.587091] [<ffffffff816d2204>] raid5d+0x64/0x790 > > [ 4481.592546] [<ffffffff810c35c6>] ? finish_wait+0x46/0x80 > > [ 4481.598583] [<ffffffff810c35e8>] ? finish_wait+0x68/0x80 > > [ 4481.604621] [<ffffffff816d8d2e>] md_thread+0x13e/0x150 > > [ 4481.610464] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 > > [ 4481.616405] [<ffffffff816d8bf0>] ? find_pers+0x80/0x80 > > [ 4481.622249] [<ffffffff8109eed5>] kthread+0x105/0x120 > > [ 4481.627899] [<ffffffff8109edd0>] ? kthread_create_on_node+0x220/0x220 > > [ 4481.635201] [<ffffffff81ca218f>] ret_from_fork+0x3f/0x70 > > [ 4481.641239] [<ffffffff8109edd0>] ? kthread_create_on_node+0x220/0x220 > > [ 4481.654638] NMI backtrace for cpu 0 > > [ 4481.658536] CPU: 0 PID: 22322 Comm: kworker/u24:2 Tainted: P W O 4.2.8 #7 > > [ 4481.667198] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 > > [ 4481.677124] Workqueue: writeback wb_workfn (flush-252:15) > > [ 4481.683160] task: ffff8805c9720a00 ti: ffff8805c84f8000 task.ti: ffff8805c84f8000 > > [ 4481.691531] RIP: 0010:[<ffffffff816cd9f1>] [<ffffffff816cd9f1>] raid5_unplug+0x71/0x270 > > [ 4481.700582] RSP: 0018:ffff8805c84fb938 EFLAGS: 00000046 > > [ 4481.706521] RAX: ffff8805cd2ce258 RBX: ffff881038557280 RCX: ffff8805cd2ce258 > > [ 4481.714502] RDX: ffff8805cd2ce258 RSI: ffff8805cd2ce248 RDI: ffff88102b242000 > > [ 4481.722483] RBP: ffff8805c84fb978 R08: ffffffff81e0a1c0 R09: 0000000000000000 > > [ 4481.730464] R10: 0000000000000000 R11: 00000000071775d0 R12: 00000000b921e53c > > [ 4481.738445] R13: ffff88102b242000 R14: ffff8810385572a0 R15: ffff88102feec000 > > [ 4481.746427] FS: 0000000000000000(0000) GS:ffff88107fc00000(0000) knlGS:0000000000000000 > > [ 4481.755477] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > > [ 4481.761904] CR2: 00007fb7bf2d2000 CR3: 0000000fff8df000 CR4: 00000000003406f0 > > [ 4481.769886] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > > [ 4481.777868] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 > > [ 4481.785848] Stack: > > [ 4481.788094] 00000000f835a020 ffff88102b242888 ffff8805c84fbb48 ffff8805c84fb9a8 > > [ 4481.796366] 0000000000000000 ffff8805c84fba28 ffff8805c84fba48 ffff8805c84fb998 > > [ 4481.804640] ffff8805c84fb9e8 ffffffff81463c8b ffff8805c84fb9d8 ffffffff81461bb2 > > [ 4481.812912] Call Trace: > > [ 4481.815644] [<ffffffff81463c8b>] blk_flush_plug_list+0x9b/0x230 > > [ 4481.822361] [<ffffffff81461bb2>] ? submit_bio+0x62/0x150 > > [ 4481.828398] [<ffffffff81464364>] blk_finish_plug+0x24/0x40 > > [ 4481.834628] [<ffffffff812292c3>] mpage_writepages+0x73/0x90 > > [ 4481.840956] [<ffffffff81222f90>] ? I_BDEV+0x10/0x10 > > [ 4481.846506] [<ffffffff81225380>] qnap_blkdev_writepages+0x10/0x20 > > [ 4481.853418] [<ffffffff81188af9>] do_writepages+0x59/0x70 > > [ 4481.859455] [<ffffffff81213874>] __writeback_single_inode+0x74/0xa50 > > [ 4481.866658] [<ffffffff81214a41>] writeback_sb_inodes+0x2f1/0x680 > > [ 4481.873472] [<ffffffff81214e54>] __writeback_inodes_wb+0x84/0xb0 > > [ 4481.880287] [<ffffffff812151a9>] wb_writeback+0x329/0x6e0 > > [ 4482.914006] NMI backtrace for cpu 5 > > [ 4482.917906] CPU: 5 PID: 26333 Comm: kworker/u24:5 Tainted: P W O 4.2.8 #7 > > [ 4482.926567] Hardware name: Default string Default string/Default string, BIOS QY38AR06 01/24/2017 > > [ 4482.936492] Workqueue: writeback wb_workfn (flush-252:14) > > [ 4482.942529] task: ffff8805c7a74340 ti: ffff8805c6228000 task.ti: ffff8805c6228000 > > [ 4482.950898] RIP: 0010:[<ffffffff8149cfd7>] [<ffffffff8149cfd7>] delay_tsc+0x17/0x70 > > [ 4482.959558] RSP: 0018:ffff8805c622b368 EFLAGS: 00000082 > > [ 4482.965498] RAX: 00000000dc0ef28f RBX: ffff88102b242888 RCX: 00000000dc0ef259 > > [ 4482.973479] RDX: 0000000000003c68 RSI: 0000000000000005 RDI: 0000000000000001 > > [ 4482.981460] RBP: ffff8805c622b368 R08: 0000000000000001 R09: 0000000000000001 > > [ 4482.989441] R10: 0000000000000000 R11: 0000000000000007 R12: 00000000763815f7 > > [ 4482.997422] R13: 0000000000000001 R14: 0000000082d0f7c8 R15: ffff88102feec000 > > [ 4483.005403] FS: 0000000000000000(0000) GS:ffff88107fca0000(0000) knlGS:0000000000000000 > > [ 4483.014459] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > > [ 4483.020876] CR2: 00007f54d805a030 CR3: 0000001006c20000 CR4: 00000000003406e0 > > [ 4483.028858] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > > [ 4483.036840] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 > > [ 4483.044822] Stack: > > [ 4483.047069] ffff8805c622b378 ffffffff8149cf2a ffff8805c622b3a8 ffffffff810d2d87 > > [ 4483.055341] ffff88102b242888 0000000000000000 ffff88102b242000 ffff881007d702a0 > > [ 4483.063613] ffff8805c622b3d8 ffffffff81ca14d1 ffffffff816cd9ca 0000000000000000 > > [ 4483.071885] Call Trace: > > [ 4483.074617] [<ffffffff8149cf2a>] __delay+0xa/0x10 > > [ 4483.079973] [<ffffffff810d2d87>] do_raw_spin_lock+0x87/0x120 > > [ 4483.086399] [<ffffffff81ca14d1>] _raw_spin_lock_irq+0x41/0x50 > > [ 4483.092920] [<ffffffff816cd9ca>] ? raid5_unplug+0x4a/0x270 > > [ 4483.099151] [<ffffffff816cd9ca>] raid5_unplug+0x4a/0x270 > > [ 4483.105188] [<ffffffff81463c8b>] blk_flush_plug_list+0x9b/0x230 > > [ 4483.111907] [<ffffffff81c9bf9d>] schedule+0x6d/0x90 > > [ 4483.117459] [<ffffffff816c9910>] __get_active_stripe.constprop.61+0x750/0x970 > > [ 4483.125539] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 > > [ 4483.131480] [<ffffffff816c9d2a>] make_request+0x1fa/0xe30 > > [ 4483.137616] [<ffffffff816ddc8e>] ? md_make_request+0x1fe/0x4b0 > > [ 4483.144238] [<ffffffff810c37e0>] ? wait_woken+0xb0/0xb0 > > [ 4483.150179] [<ffffffff816ddc52>] ? md_make_request+0x1c2/0x4b0 > > [ 4483.156800] [<ffffffff816ddc8e>] md_make_request+0x1fe/0x4b0 > > [ 4483.163227] [<ffffffff816ddade>] ? md_make_request+0x4e/0x4b0 > > [ 4483.169750] [<ffffffff816edd43>] ? dm_make_request+0x73/0x110 > > [ 4483.176273] [<ffffffff81461b0e>] generic_make_request+0xce/0x110 > > > > ^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2017-09-06 3:17 UTC | newest] Thread overview: 5+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2017-08-28 12:01 [PATCH] md/raid5: preserve STRIPE_ON_UNPLUG_LIST in break_stripe_batch_list Dennis Yang 2017-09-01 5:38 ` Shaohua Li 2017-09-01 9:26 ` Dennis Yang 2017-09-05 19:24 ` Shaohua Li 2017-09-06 3:17 ` Dennis Yang
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).