On Wed, Dec 30, 2015 at 5:45 AM, Artur Paszkiewicz <artur.paszkiewicz@xxxxxxxxx> wrote: > Hi, > > I'm seeing a hang when trying to stop a RAID5 array that is undergoing > reshape: > > [ 99.629924] md: reshape of RAID array md0 > [ 99.631150] md: minimum _guaranteed_ speed: 1000 KB/sec/disk. > [ 99.632737] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for reshape. > [ 99.635366] md: using 128k window, over a total of 1047552k. > [ 103.819848] md: md0: reshape interrupted. > [ 150.127132] INFO: task md0_raid5:3234 blocked for more than 30 seconds. > [ 150.128717] Not tainted 4.4.0-rc5+ #54 > [ 150.129939] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [ 150.132116] md0_raid5 D ffff88003b1d7ba0 14104 3234 2 0x00000000 > [ 150.134081] ffff88003b1d7ba0 ffffffff81e104c0 ffff88003bad0000 ffff88003b1d8000 > [ 150.137205] ffff88003d66380c 0000000000000001 ffff88003d663a50 ffff88003d663800 > [ 150.139994] ffff88003b1d7bb8 ffffffff81876050 ffff88003d663800 ffff88003b1d7c28 > [ 150.142606] Call Trace: > [ 150.143551] [<ffffffff81876050>] schedule+0x30/0x80 > [ 150.144883] [<ffffffffa005fc80>] raid5_quiesce+0x200/0x250 [raid456] > [ 150.147964] [<ffffffff810882a0>] ? prepare_to_wait_event+0xf0/0xf0 > [ 150.149661] [<ffffffffa0003bca>] mddev_suspend.part.26+0x7a/0x90 [md_mod] > [ 150.151376] [<ffffffffa0003bf7>] mddev_suspend+0x17/0x20 [md_mod] > [ 150.153268] [<ffffffffa0064e29>] check_reshape+0xb9/0x6b0 [raid456] > [ 150.154869] [<ffffffff8107e63f>] ? set_next_entity+0x9f/0x6d0 > [ 150.156359] [<ffffffff8107af68>] ? sched_clock_local+0x18/0x80 > [ 150.157848] [<ffffffff81081400>] ? pick_next_entity+0xa0/0x150 > [ 150.159348] [<ffffffff810830ae>] ? pick_next_task_fair+0x3fe/0x460 > [ 150.160887] [<ffffffffa0065471>] raid5_check_reshape+0x51/0xa0 [raid456] > [ 150.162482] [<ffffffffa000ba59>] md_check_recovery+0x2f9/0x480 [md_mod] > [ 150.164074] [<ffffffffa00697b4>] raid5d+0x34/0x650 [raid456] > [ 150.165751] [<ffffffff81876050>] ? schedule+0x30/0x80 > [ 150.167508] [<ffffffff818786ef>] ? schedule_timeout+0x1ef/0x270 > [ 150.169784] [<ffffffff81875ac3>] ? __schedule+0x313/0x870 > [ 150.171194] [<ffffffffa0002e61>] md_thread+0x111/0x130 [md_mod] > [ 150.172671] [<ffffffff810882a0>] ? prepare_to_wait_event+0xf0/0xf0 > [ 150.174206] [<ffffffffa0002d50>] ? find_pers+0x70/0x70 [md_mod] > [ 150.175697] [<ffffffff8106c8d4>] kthread+0xc4/0xe0 > [ 150.178294] [<ffffffff8106c810>] ? kthread_park+0x50/0x50 > [ 150.179745] [<ffffffff818796df>] ret_from_fork+0x3f/0x70 > [ 150.181134] [<ffffffff8106c810>] ? kthread_park+0x50/0x50 > > Two tasks end up blocked: > 3866 ? D 0:00 [systemd-udevd] > 4051 ? D 0:00 [md0_raid5] > > This happens when udev change event is triggered by mdadm -S and it > causes some reads on the array. I think the hang occurs because > raid5_quiesce() is called from the raid5d thread and it blocks waiting > for active_stripes to become 0, which won't happen, since stripes are > released by raid5d. Commit 738a273 ("md/raid5: fix allocation of > 'scribble' array.") added mddev_suspend() in resize_chunks(), causing > this problem. Skipping mddev_suspend()/mddev_resume() in resize_chunks() > when running in raid5d context seems to fix it, but I don't think that's > a correct fix... One approach to spotting the correct fix might be to go add lockdep annotations to validate the "locking" order of these events. See the usage of: lock_map_acquire(&wq->lockdep_map); lock_map_release(&wq->lockdep_map); ...in the workqueue code as a way to validate flush ordering. For example you want lockdep to report when the current thread would deadlock due to a circular or ABBA dependency. -- To unsubscribe from this list: send the line "unsubscribe linux-raid" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html