From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Date: Thu, 2 Aug 2018 18:33:54 +0800 From: Ming Lei To: Adrian Hunter Cc: Peter Geis , Linus Walleij , Ulf Hansson , Jens Axboe , linux-block@vger.kernel.org, "linux-tegra@vger.kernel.org" Subject: Re: [Regression] Linux-Next Merge 25Jul2018 breaks mmc on Tegra. Message-ID: <20180802103353.GA6520@ming.t460p> References: <835eb17a-e192-d991-04b6-f0c82c32311e@kernel.dk> <20180728133654.GA8047@ming.t460p> <4284a9b0-2d90-3ffa-0172-9ec5d8f6f8af@gmail.com> <20180731013848.GA6740@ming.t460p> <20180731162518.GA18025@ming.t460p> <8550a541-5cf6-f1ff-025e-67c6b404dd0d@intel.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii In-Reply-To: <8550a541-5cf6-f1ff-025e-67c6b404dd0d@intel.com> List-ID: On Thu, Aug 02, 2018 at 01:09:31PM +0300, Adrian Hunter wrote: > On 31/07/18 19:25, Ming Lei wrote: > > Hi Peter, > > > > On Tue, Jul 31, 2018 at 08:47:45AM -0400, Peter Geis wrote: > >> Good Morning, > >> > >> On 07/30/2018 09:38 PM, Ming Lei wrote: > >>> Hi Peter, > >>> > >>> Thanks for collecting the log. > >>> > >>> On Mon, Jul 30, 2018 at 02:55:42PM -0400, Peter Geis wrote: > >>>> > >>>> > >>>> On 07/28/2018 09:37 AM, Ming Lei wrote: > >>> > >>> ... > >>> > >>>> [ 10.887209] systemd--112 0.n.1 2411122us : blk_mq_make_request: make > >>>> rq -1 > >>>> [ 10.890274] kworker/-98 0...1 2411506us : blk_mq_free_request: > >>>> complete: rq -1 > >>>> [ 10.893313] systemd--107 0...1 2412025us : blk_mq_make_request: make > >>>> rq -1 > >>>> [ 10.896354] systemd--107 0.... 2412323us : mmc_mq_queue_rq: queue rq > >>>> -1, 0 > >>>> [ 10.899388] systemd--107 0.... 2412327us : > >>>> blk_mq_try_issue_list_directly: issue direct: rq -1, ret 0 > >>>> [ 10.902463] (direxec-111 1...1 2413829us : blk_mq_make_request: make > >>>> rq -1 > >>>> [ 10.905513] systemd--114 1...1 2415159us : blk_mq_make_request: make > >>>> rq -1 > >>> > >>> Above is the most interesting part in the log. MMC sets hw queue depth > >>> as 1, and you are using none scheduler, that means the max number of > >>> in-flight requests should be one, but the above log shows that there may > >>> be 3 in-flight requests. > >> > >> That's odd, I have CFQ set as the default, is something changing this during > >> boot? > >> CONFIG_CFQ_GROUP_IOSCHED=y > >> CONFIG_DEFAULT_IOSCHED="cfq" > > > > No, now mmc has been converted to blk-mq, and the default mq io sched > > should have been mq-deadline for mmc, but not sure why it is none in > > your case. > > > >> > >>> > >>> That seems really weird, but it shouldn't be related with my two patches, > >>> which won't change the tag allocation behaviour at all. However, what matters > >>> may be that the patch speeds up the request dispatch. Maybe one bug > >>> in lib/sbitmap.c block/blk-mq-tag.c. > >>> > >>> Unfortunately rq->tag wasn't shown in the log because I forget to dump > >>> it in the debug patch, so could you apply the following new debug patch and > >>> provide us the log again? BTW, please attach the ftrace log in the reply > >>> mail directly, then it may be parsed/looked easily. > >> > >> I have resynced to the latest linux-next and applied your new patch. > >> The log is attached. > >> > >> Of note, it took several boots this time before it would progress to where I > >> could grab the log. > >> Instead it was blocking the moment RW was requested. > >> Also of note, it seems only the emmc is affected, the SD card (mmcblk2) does > >> not trigger any errors. > > > >>From the log you captured, seems there are three requests(33, 34, 60) blocked, > > which should have been inside mmc, but still need to confirm, could you apply the > > following one-line patch against the last debug patch and collect the log again? > > > > diff --git a/drivers/mmc/core/queue.c b/drivers/mmc/core/queue.c > > index d35f265cd5e0..ac2ffc5a8ed4 100644 > > --- a/drivers/mmc/core/queue.c > > +++ b/drivers/mmc/core/queue.c > > @@ -321,6 +321,8 @@ static blk_status_t mmc_mq_queue_rq(struct blk_mq_hw_ctx *hctx, > > !host->hold_retune; > > } > > > > + if (blk_queue_debug(q)) > > + trace_printk("mmc before issue rq %d %d\n", req->internal_tag, req->tag); > > blk_mq_start_request(req); > > > > issued = mmc_blk_mq_issue_rq(mq, req); > > > > > > Also see comments in mmc_mq_queue_rq(): > > > > /* > > * We use BLK_MQ_F_BLOCKING and have only 1 hardware queue, which means requests > > * will not be dispatched in parallel. > > */ > > > > which isn't correct, given blk-mq has multiple sw queue and mmc sets the queue depth > > as > 1, and requests may be dispatched to the unique hw queue in parallel. > > > > Adrian, Ulf Hansson and anyone, could you take a look at the warning of WARN_ON(host->cmd) > > in sdhci_send_command()? Seems you only allow to queue one command, but not sure how you > > guarantee that. > > We didn't guarantee it, but it didn't happen before "blk-mq: issue directly > if hw queue isn't busy in case of 'none'". OK, thanks for clarifying that, and as I mentioned what matters is the timing change. > We did consider adding a mutex, refer > https://lore.kernel.org/lkml/CAPDyKFr8tiJXSL-weQjGJ3DfRrfv8ZAFY8=ZECLNgSe_43S8Rw@mail.gmail.com/ > > However the following might do, do you think? If dispatch in parallel isn't supported, just wondering why not set hw queue depth as 1? That way should be simple to fix this issue. > > > diff --git a/drivers/mmc/core/queue.c b/drivers/mmc/core/queue.c > index 648eb6743ed5..6edffeed9953 100644 > --- a/drivers/mmc/core/queue.c > +++ b/drivers/mmc/core/queue.c > @@ -238,10 +238,6 @@ static void mmc_mq_exit_request(struct blk_mq_tag_set *set, struct request *req, > mmc_exit_request(mq->queue, req); > } > > -/* > - * We use BLK_MQ_F_BLOCKING and have only 1 hardware queue, which means requests > - * will not be dispatched in parallel. > - */ > static blk_status_t mmc_mq_queue_rq(struct blk_mq_hw_ctx *hctx, > const struct blk_mq_queue_data *bd) > { > @@ -264,7 +260,7 @@ static blk_status_t mmc_mq_queue_rq(struct blk_mq_hw_ctx *hctx, > > spin_lock_irq(q->queue_lock); > > - if (mq->recovery_needed) { > + if (mq->recovery_needed || mq->busy) { > spin_unlock_irq(q->queue_lock); > return BLK_STS_RESOURCE; > } > @@ -291,6 +287,9 @@ static blk_status_t mmc_mq_queue_rq(struct blk_mq_hw_ctx *hctx, > break; > } > > + /* Parallel dispatch of requests is not supported at the moment */ > + mq->busy = true; > + > mq->in_flight[issue_type] += 1; > get_card = (mmc_tot_in_flight(mq) == 1); > cqe_retune_ok = (mmc_cqe_qcnt(mq) == 1); > @@ -333,9 +332,12 @@ static blk_status_t mmc_mq_queue_rq(struct blk_mq_hw_ctx *hctx, > mq->in_flight[issue_type] -= 1; > if (mmc_tot_in_flight(mq) == 0) > put_card = true; > + mq->busy = false; > spin_unlock_irq(q->queue_lock); > if (put_card) > mmc_put_card(card, &mq->ctx); > + } else { > + WRITE_ONCE(mq->busy, false); > } > > return ret; > diff --git a/drivers/mmc/core/queue.h b/drivers/mmc/core/queue.h > index 17e59d50b496..9bf3c9245075 100644 > --- a/drivers/mmc/core/queue.h > +++ b/drivers/mmc/core/queue.h > @@ -81,6 +81,7 @@ struct mmc_queue { > unsigned int cqe_busy; > #define MMC_CQE_DCMD_BUSY BIT(0) > #define MMC_CQE_QUEUE_FULL BIT(1) > + bool busy; > bool use_cqe; > bool recovery_needed; > bool in_recovery; Sorry, I am not familiar with mmc code, so can't comment on the above patch. Thanks, Ming