From mboxrd@z Thu Jan 1 00:00:00 1970 From: Bartlomiej Zolnierkiewicz Subject: Re: [PATCH 11/16] mmc: block: shuffle retry and error handling Date: Wed, 01 Mar 2017 16:58:19 +0100 Message-ID: <1736240.zsmNExgN5W@amdc3058> References: <20170209153403.9730-1-linus.walleij@linaro.org> <1718299.ToPxjyb5YA@amdc3058> <18156581.sUHfslyV5F@amdc3058> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: 7Bit Return-path: Received: from mailout2.samsung.com ([203.254.224.25]:44031 "EHLO mailout2.samsung.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752472AbdCAQA3 (ORCPT ); Wed, 1 Mar 2017 11:00:29 -0500 In-reply-to: <18156581.sUHfslyV5F@amdc3058> Sender: linux-mmc-owner@vger.kernel.org List-Id: linux-mmc@vger.kernel.org To: Linus Walleij Cc: linux-mmc@vger.kernel.org, Ulf Hansson , Adrian Hunter , Paolo Valente , Chunyan Zhang , Baolin Wang , linux-block@vger.kernel.org, Jens Axboe , Christoph Hellwig , Arnd Bergmann On Wednesday, March 01, 2017 04:52:38 PM Bartlomiej Zolnierkiewicz wrote: > I assume that the problem got introduced even earlier, > commit 4515dc6 ("mmc: block: shuffle retry and error > handling") just makes it happen every time. Patch #16 makes it worse as now I get deadlock on boot: [ 248.801750] INFO: task kworker/2:2:113 blocked for more than 120 seconds. [ 248.807119] Tainted: G W 4.10.0-rc3-00123-g1bec9a6 #2726 [ 248.814162] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 248.821943] kworker/2:2 D 0 113 2 0x00000000 [ 248.827357] Workqueue: events_freezable mmc_rescan [ 248.832227] [] (__schedule) from [] (schedule+0x40/0xac) [ 248.839123] [] (schedule) from [] (__mmc_claim_host+0x8c/0x1a0) [ 248.846851] [] (__mmc_claim_host) from [] (mmc_attach_mmc+0xb8/0x14c) [ 248.854989] [] (mmc_attach_mmc) from [] (mmc_rescan+0x274/0x34c) [ 248.862725] [] (mmc_rescan) from [] (process_one_work+0x120/0x318) [ 248.870498] [] (process_one_work) from [] (worker_thread+0x2c/0x4ac) [ 248.878653] [] (worker_thread) from [] (kthread+0xfc/0x134) [ 248.885934] [] (kthread) from [] (ret_from_fork+0x14/0x3c) [ 248.893098] INFO: task jbd2/mmcblk0p2-:132 blocked for more than 120 seconds. [ 248.900092] Tainted: G W 4.10.0-rc3-00123-g1bec9a6 #2726 [ 248.907108] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 248.914904] jbd2/mmcblk0p2- D 0 132 2 0x00000000 [ 248.920319] [] (__schedule) from [] (schedule+0x40/0xac) [ 248.927433] [] (schedule) from [] (schedule_timeout+0x148/0x220) [ 248.935139] [] (schedule_timeout) from [] (io_schedule_timeout+0x74/0xb0) [ 248.943634] [] (io_schedule_timeout) from [] (bit_wait_io+0x10/0x58) [ 248.951684] [] (bit_wait_io) from [] (__wait_on_bit+0x84/0xbc) [ 248.959134] [] (__wait_on_bit) from [] (out_of_line_wait_on_bit+0x68/0x70) [ 248.968142] [] (out_of_line_wait_on_bit) from [] (jbd2_journal_commit_transaction+0x1468/0x15c4) [ 248.978397] [] (jbd2_journal_commit_transaction) from [] (kjournald2+0xbc/0x264) [ 248.987514] [] (kjournald2) from [] (kthread+0xfc/0x134) [ 248.994494] [] (kthread) from [] (ret_from_fork+0x14/0x3c) [ 249.001714] INFO: task kworker/1:2H:134 blocked for more than 120 seconds. [ 249.008412] Tainted: G W 4.10.0-rc3-00123-g1bec9a6 #2726 [ 249.015479] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 249.023094] kworker/1:2H D 0 134 2 0x00000000 [ 249.028510] Workqueue: kblockd blk_mq_run_work_fn [ 249.033330] [] (__schedule) from [] (schedule+0x40/0xac) [ 249.040199] [] (schedule) from [] (__mmc_claim_host+0x8c/0x1a0) [ 249.047856] [] (__mmc_claim_host) from [] (mmc_queue_rq+0x9c/0xa8) [ 249.055736] [] (mmc_queue_rq) from [] (blk_mq_dispatch_rq_list+0xd4/0x1d0) [ 249.064316] [] (blk_mq_dispatch_rq_list) from [] (blk_mq_process_rq_list+0x180/0x198) [ 249.073845] [] (blk_mq_process_rq_list) from [] (__blk_mq_run_hw_queue+0xb8/0x110) [ 249.083120] [] (__blk_mq_run_hw_queue) from [] (process_one_work+0x120/0x318) [ 249.092076] [] (process_one_work) from [] (worker_thread+0x2c/0x4ac) [ 249.099990] [] (worker_thread) from [] (kthread+0xfc/0x134) [ 249.107322] [] (kthread) from [] (ret_from_fork+0x14/0x3c) [ 249.114485] INFO: task kworker/5:2H:136 blocked for more than 120 seconds. [ 249.121326] Tainted: G W 4.10.0-rc3-00123-g1bec9a6 #2726 [ 249.128232] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 249.136074] kworker/5:2H D 0 136 2 0x00000000 [ 249.141544] Workqueue: kblockd blk_mq_run_work_fn [ 249.146187] [] (__schedule) from [] (schedule+0x40/0xac) [ 249.153419] [] (schedule) from [] (__mmc_claim_host+0x8c/0x1a0) [ 249.160825] [] (__mmc_claim_host) from [] (mmc_queue_rq+0x9c/0xa8) [ 249.168755] [] (mmc_queue_rq) from [] (blk_mq_dispatch_rq_list+0xd4/0x1d0) [ 249.177318] [] (blk_mq_dispatch_rq_list) from [] (blk_mq_process_rq_list+0x180/0x198) [ 249.186858] [] (blk_mq_process_rq_list) from [] (__blk_mq_run_hw_queue+0xb8/0x110) [ 249.196124] [] (__blk_mq_run_hw_queue) from [] (process_one_work+0x120/0x318) [ 249.204969] [] (process_one_work) from [] (worker_thread+0x2c/0x4ac) [ 249.213161] [] (worker_thread) from [] (kthread+0xfc/0x134) [ 249.220270] [] (kthread) from [] (ret_from_fork+0x14/0x3c) [ 249.227505] INFO: task kworker/0:1H:145 blocked for more than 120 seconds. [ 249.234328] Tainted: G W 4.10.0-rc3-00123-g1bec9a6 #2726 [ 249.241229] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 249.249066] kworker/0:1H D 0 145 2 0x00000000 [ 249.254521] Workqueue: kblockd blk_mq_run_work_fn [ 249.259176] [] (__schedule) from [] (schedule+0x40/0xac) [ 249.266233] [] (schedule) from [] (__mmc_claim_host+0x8c/0x1a0) [ 249.274001] [] (__mmc_claim_host) from [] (mmc_queue_rq+0x9c/0xa8) [ 249.281747] [] (mmc_queue_rq) from [] (blk_mq_dispatch_rq_list+0xd4/0x1d0) [ 249.290284] [] (blk_mq_dispatch_rq_list) from [] (blk_mq_process_rq_list+0x180/0x198) [ 249.299843] [] (blk_mq_process_rq_list) from [] (__blk_mq_run_hw_queue+0xb8/0x110) [ 249.309122] [] (__blk_mq_run_hw_queue) from [] (process_one_work+0x120/0x318) [ 249.317951] [] (process_one_work) from [] (worker_thread+0x2c/0x4ac) [ 249.326017] [] (worker_thread) from [] (kthread+0xfc/0x134) [ 249.333408] [] (kthread) from [] (ret_from_fork+0x14/0x3c) [ 249.340459] INFO: task udevd:280 blocked for more than 120 seconds. [ 249.346725] Tainted: G W 4.10.0-rc3-00123-g1bec9a6 #2726 [ 249.353644] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 249.361452] udevd D 0 280 258 0x00000005 [ 249.366885] [] (__schedule) from [] (schedule+0x40/0xac) [ 249.373964] [] (schedule) from [] (schedule_timeout+0x148/0x220) [ 249.381651] [] (schedule_timeout) from [] (io_schedule_timeout+0x74/0xb0) [ 249.390110] [] (io_schedule_timeout) from [] (__lock_page+0xe8/0x118) [ 249.398399] [] (__lock_page) from [] (truncate_inode_pages_range+0x580/0x59c) [ 249.407129] [] (truncate_inode_pages_range) from [] (truncate_inode_pages+0x18/0x20) [ 249.416571] [] (truncate_inode_pages) from [] (__blkdev_put+0x68/0x1d8) [ 249.424892] [] (__blkdev_put) from [] (blkdev_close+0x18/0x20) [ 249.432422] [] (blkdev_close) from [] (__fput+0x84/0x1c0) [ 249.439501] [] (__fput) from [] (task_work_run+0xbc/0xdc) [ 249.446677] [] (task_work_run) from [] (do_exit+0x304/0x9bc) [ 249.454152] [] (do_exit) from [] (do_group_exit+0x3c/0xbc) [ 249.461165] [] (do_group_exit) from [] (get_signal+0x200/0x65c) [ 249.468833] [] (get_signal) from [] (do_signal+0x84/0x3c4) [ 249.476015] [] (do_signal) from [] (do_work_pending+0xa4/0xb4) [ 249.483557] [] (do_work_pending) from [] (slow_work_pending+0xc/0x20) [ 249.491689] INFO: task udevd:281 blocked for more than 120 seconds. [ 249.497900] Tainted: G W 4.10.0-rc3-00123-g1bec9a6 #2726 [ 249.504892] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 249.512771] udevd D 0 281 258 0x00000005 [ 249.518097] [] (__schedule) from [] (schedule+0x40/0xac) [ 249.525153] [] (schedule) from [] (schedule_timeout+0x148/0x220) [ 249.532853] [] (schedule_timeout) from [] (io_schedule_timeout+0x74/0xb0) [ 249.541354] [] (io_schedule_timeout) from [] (__lock_page+0xe8/0x118) [ 249.549463] [] (__lock_page) from [] (truncate_inode_pages_range+0x580/0x59c) [ 249.558331] [] (truncate_inode_pages_range) from [] (truncate_inode_pages+0x18/0x20) [ 249.567785] [] (truncate_inode_pages) from [] (__blkdev_put+0x68/0x1d8) [ 249.576207] [] (__blkdev_put) from [] (blkdev_close+0x18/0x20) [ 249.583669] [] (blkdev_close) from [] (__fput+0x84/0x1c0) [ 249.590710] [] (__fput) from [] (task_work_run+0xbc/0xdc) [ 249.597843] [] (task_work_run) from [] (do_exit+0x304/0x9bc) [ 249.605217] [] (do_exit) from [] (do_group_exit+0x3c/0xbc) [ 249.612399] [] (do_group_exit) from [] (get_signal+0x200/0x65c) [ 249.620000] [] (get_signal) from [] (do_signal+0x84/0x3c4) [ 249.627228] [] (do_signal) from [] (do_work_pending+0xa4/0xb4) [ 249.634874] [] (do_work_pending) from [] (slow_work_pending+0xc/0x20) [ 249.642922] INFO: task kworker/u16:2:1268 blocked for more than 120 seconds. [ 249.649891] Tainted: G W 4.10.0-rc3-00123-g1bec9a6 #2726 [ 249.656847] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 249.664654] kworker/u16:2 D 0 1268 2 0x00000000 [ 249.670094] Workqueue: writeback wb_workfn (flush-179:0) [ 249.675398] [] (__schedule) from [] (schedule+0x40/0xac) [ 249.682425] [] (schedule) from [] (schedule_timeout+0x148/0x220) [ 249.690103] [] (schedule_timeout) from [] (io_schedule_timeout+0x74/0xb0) [ 249.698738] [] (io_schedule_timeout) from [] (bt_get+0x140/0x228) [ 249.706432] [] (bt_get) from [] (blk_mq_get_tag+0x24/0xa8) [ 249.713613] [] (blk_mq_get_tag) from [] (__blk_mq_alloc_request+0x10/0x15c) [ 249.722287] [] (__blk_mq_alloc_request) from [] (blk_mq_map_request+0xb0/0xfc) [ 249.731178] [] (blk_mq_map_request) from [] (blk_sq_make_request+0x8c/0x298) [ 249.739962] [] (blk_sq_make_request) from [] (generic_make_request+0xd8/0x180) [ 249.748891] [] (generic_make_request) from [] (submit_bio+0x88/0x148) [ 249.757175] [] (submit_bio) from [] (ext4_io_submit+0x34/0x40) [ 249.764581] [] (ext4_io_submit) from [] (ext4_writepages+0x484/0x670) [ 249.772722] [] (ext4_writepages) from [] (do_writepages+0x24/0x38) [ 249.780573] [] (do_writepages) from [] (__writeback_single_inode+0x28/0x18c) [ 249.789359] [] (__writeback_single_inode) from [] (writeback_sb_inodes+0x1e0/0x394) [ 249.798717] [] (writeback_sb_inodes) from [] (__writeback_inodes_wb+0x70/0xac) [ 249.807643] [] (__writeback_inodes_wb) from [] (wb_writeback+0x18c/0x1b4) [ 249.816241] [] (wb_writeback) from [] (wb_workfn+0x1c8/0x388) [ 249.823590] [] (wb_workfn) from [] (process_one_work+0x120/0x318) [ 249.831375] [] (process_one_work) from [] (worker_thread+0x2c/0x4ac) [ 249.839408] [] (worker_thread) from [] (kthread+0xfc/0x134) [ 249.846726] [] (kthread) from [] (ret_from_fork+0x14/0x3c) Best regards, -- Bartlomiej Zolnierkiewicz Samsung R&D Institute Poland Samsung Electronics