Re: [PATCH V4 09/11] mmc: block: Add CQE support

[Adrian Hunter <adrian.hunter@intel.com>]

On 09/08/17 03:55, Shawn Lin wrote:
> Hi,
> 
> On 2017/8/8 20:07, Bough Chen wrote:
>>> -----Original Message-----
>>> From: Adrian Hunter [mailto:adrian.hunter@intel.com]
>>> Sent: Friday, July 21, 2017 5:50 PM
>>> To: Ulf Hansson <ulf.hansson@linaro.org>
>>> Cc: linux-mmc <linux-mmc@vger.kernel.org>; Bough Chen
>>> <haibo.chen@nxp.com>; Alex Lemberg <alex.lemberg@sandisk.com>;
>>> Mateusz Nowak <mateusz.nowak@intel.com>; Yuliy Izrailov
>>> <Yuliy.Izrailov@sandisk.com>; Jaehoon Chung <jh80.chung@samsung.com>;
>>> Dong Aisheng <dongas86@gmail.com>; Das Asutosh
>>> <asutoshd@codeaurora.org>; Zhangfei Gao <zhangfei.gao@gmail.com>;
>>> Dorfman Konstantin <kdorfman@codeaurora.org>; David Griego
>>> <david.griego@linaro.org>; Sahitya Tummala <stummala@codeaurora.org>;
>>> Harjani Ritesh <riteshh@codeaurora.org>; Venu Byravarasu
>>> <vbyravarasu@nvidia.com>; Linus Walleij <linus.walleij@linaro.org>; Shawn
>>> Lin
>>> <shawn.lin@rock-chips.com>
>>> Subject: [PATCH V4 09/11] mmc: block: Add CQE support
>>>
>>> Add CQE support to the block driver, including:
>>>     - optionally using DCMD for flush requests
>>>     - manually issuing discard requests
>>>     - issuing read / write requests to the CQE
>>>     - supporting block-layer timeouts
>>>     - handling recovery
>>>     - supporting re-tuning
>>>
>>> Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
>>> ---
>>>   drivers/mmc/core/block.c | 195 ++++++++++++++++++++++++++++++++-
>>>   drivers/mmc/core/block.h |   7 ++
>>>   drivers/mmc/core/queue.c | 273
>>> ++++++++++++++++++++++++++++++++++++++++++++++-
>>>   drivers/mmc/core/queue.h |  42 +++++++-
>>>   4 files changed, 510 insertions(+), 7 deletions(-)
>>>
>>> diff --git a/drivers/mmc/core/block.c b/drivers/mmc/core/block.c index
>>> 915290c74363..2d25115637b7 100644
>>> --- a/drivers/mmc/core/block.c
>>> +++ b/drivers/mmc/core/block.c
>>> @@ -109,6 +109,7 @@ struct mmc_blk_data {
>>>   #define MMC_BLK_WRITE        BIT(1)
>>>   #define MMC_BLK_DISCARD        BIT(2)
>>>   #define MMC_BLK_SECDISCARD    BIT(3)
>>> +#define MMC_BLK_CQE_RECOVERY    BIT(4)
>>>
>>>       /*
>>>        * Only set in main mmc_blk_data associated @@ -1612,6 +1613,198
>>> @@ static void mmc_blk_data_prep(struct mmc_queue *mq, struct
>>> mmc_queue_req *mqrq,
>>>           *do_data_tag_p = do_data_tag;
>>>   }
>>>
>>> +#define MMC_CQE_RETRIES 2
> 
> 
>>> +        blk_queue_rq_timed_out(mq->queue, mmc_cqe_timed_out);
>>> +        blk_queue_rq_timeout(mq->queue, 60 * HZ);
>>
> 
> ------8<-------
> 
>> Hi Adrian,
>>
>> These days I'm doing CMDQ stress test, and find one issue.
>> On our i.MX8QXP-ARM2 board, the RAM is 3GB. eMMC is 32GB.
>> I use command 'free -m' get the total memory is 2800M, and the free memory
>> is 2500M.
>>
>> I use 'mkfs.ext4' to format ext4 file system on the eMMC under HS400ES
>> CMDQ mode, works fine.
>>
>> When I use the following command to stress test CMDQ, it works fine.
>> bonnie++ -d /run/media/mmcblk0p1/ -u 0:0 -s 2048 -r 1024
>>
>> But when I change to use a large file size to do the same stress test, using
>> bonnie++ -d /run/media/mmcblk0p1/ -u 0:0 -s 4096 -r 2048
>> or
>> bonnie++ -d /run/media/mmcblk0p1/ -u 0:0 -s 5600
>>
>> I get the following dump message.  According to the log,
>> mmc_cqe_timed_out() was trigged.
>> Seems mmc was blocked in somewhere.
>> Then I try to debug this issue, and open MMC_DEBUG in config, do the same
>> test, print the detail
>> Command sending information on the console, but finally can't reproduce.

mmc_cqe_timed_out() is a 60 second timeout provided by the block layer.
Refer "blk_queue_rq_timeout(mq->queue, 60 * HZ)" in mmc_init_queue().  60s
is quite a long time so I would first want to determine if the task was
really queued that long.  I would instrument some code into cqhci_request()
to record the start time on struct mmc_request, and then print the time
taken when there is a problem.

>>
>> Shawn,
>> Can you have a try on your side?
>>
> 
> I think bonnie++ is almost the same disk test tool as iozone or fio. I
> didn't saw this when testing CMDQ by fio, but I will try bonnie++ late
> this week.
> 
> 
>>
>> [  738.385610] mmc0: cqhci: timeout for tag 1
>> [  738.389719] mmc0: cqhci: ============ CQHCI REGISTER DUMP ===========
>> [  738.396164] mmc0: cqhci: Caps:      0x0000310a | Version:  0x00000510
>> [  738.402601] mmc0: cqhci: Config:    0x00001001 | Control:  0x00000000
>> [  738.409038] mmc0: cqhci: Int stat:  0x00000000 | Int enab: 0x00000006
>> [  738.415475] mmc0: cqhci: Int sig:   0x00000006 | Int Coal: 0x00000000
>> [  738.421913] mmc0: cqhci: TDL base:  0x9007a000 | TDL up32: 0x00000000
>> [  738.428350] mmc0: cqhci: Doorbell:  0x1fffffff | TCN:      0x00000000
>> [  738.434788] mmc0: cqhci: Dev queue: 0x1f7fffff | Dev Pend: 0x1fffefff
>> [  738.441226] mmc0: cqhci: Task clr:  0x00000000 | SSC1:     0x00011000
>> [  738.447663] mmc0: cqhci: SSC2:      0x00000001 | DCMD rsp: 0x00000800
>> [  738.454100] mmc0: cqhci: RED mask:  0xfdf9a080 | TERRI:    0x00000000
>> [  738.460538] mmc0: cqhci: Resp idx:  0x0000002f | Resp arg: 0x00000900
>> [  738.466975] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
>> [  738.473414] mmc0: sdhci: Sys addr:  0xb6512000 | Version:  0x00000002
>> [  738.479850] mmc0: sdhci: Blk size:  0x00000200 | Blk cnt:  0x00000400
>> [  738.486288] mmc0: sdhci: Argument:  0x000c0400 | Trn mode: 0x00000023
>> [  738.492725] mmc0: sdhci: Present:   0x01fd858f | Host ctl: 0x00000030
>> [  738.499162] mmc0: sdhci: Power:     0x00000002 | Blk gap:  0x00000080
>> [  738.505600] mmc0: sdhci: Wake-up:   0x00000008 | Clock:    0x0000000f
>> [  738.512037] mmc0: sdhci: Timeout:   0x0000008f | Int stat: 0x00000000
>> [  738.518475] mmc0: sdhci: Int enab:  0x107f4000 | Sig enab: 0x107f4000
>> [  738.524912] mmc0: sdhci: AC12 err:  0x00000000 | Slot int: 0x00000502
>> [  738.531350] mmc0: sdhci: Caps:      0x07eb0000 | Caps_1:   0x8000b407
>> [  738.537787] mmc0: sdhci: Cmd:       0x00002c1a | Max curr: 0x00ffffff
>> [  738.544225] mmc0: sdhci: Resp[0]:   0x00000900 | Resp[1]:  0xffffffff
>> [  738.550662] mmc0: sdhci: Resp[2]:   0x328f5903 | Resp[3]:  0x00d02700
>> [  738.557099] mmc0: sdhci: Host ctl2: 0x00000008
>> [  738.561540] mmc0: sdhci: ADMA Err:  0x00000009 | ADMA Ptr: 0x90098400
>> [  738.567975] mmc0: sdhci: ============================================
>> [  738.574449] mmc0: running CQE recovery
>> [  738.593643] mmc0: Unexpected interrupt 0x00004000.
>> [  738.598436] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
>> [  738.604881] mmc0: sdhci: Sys addr:  0x00000000 | Version:  0x00000002
>> [  738.611318] mmc0: sdhci: Blk size:  0x00000200 | Blk cnt:  0x00000400
>> [  738.617756] mmc0: sdhci: Argument:  0x01af6800 | Trn mode: 0x00000023
>> [  738.624193] mmc0: sdhci: Present:   0x01fd8009 | Host ctl: 0x00000031
>> [  738.630630] mmc0: sdhci: Power:     0x00000002 | Blk gap:  0x00000080
>> [  738.637068] mmc0: sdhci: Wake-up:   0x00000008 | Clock:    0x0000000f
>> [  738.643505] mmc0: sdhci: Timeout:   0x0000008f | Int stat: 0x00004000
>> [  738.649943] mmc0: sdhci: Int enab:  0x007f1003 | Sig enab: 0x007f1003
>> [  738.656380] mmc0: sdhci: AC12 err:  0x00000000 | Slot int: 0x00000502
>> [  738.662818] mmc0: sdhci: Caps:      0x07eb0000 | Caps_1:   0x8000b407
>> [  738.669255] mmc0: sdhci: Cmd:       0x00002d12 | Max curr: 0x00ffffff
>> [  738.675693] mmc0: sdhci: Resp[0]:   0x00000c00 | Resp[1]:  0xffffffff
>> [  738.682130] mmc0: sdhci: Resp[2]:   0x328f5903 | Resp[3]:  0x00d02700
>> [  738.688566] mmc0: sdhci: Host ctl2: 0x00000008
>> [  738.693008] mmc0: sdhci: ADMA Err:  0x00000000 | ADMA Ptr: 0x00000000
>> [  738.699443] mmc0: sdhci: ============================================
>> [  738.715999] mmc0: Controller never released inhibit bit(s).
>> [  738.721573] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
>> [  738.728018] mmc0: sdhci: Sys addr:  0x00000000 | Version:  0x00000002
>> [  738.734455] mmc0: sdhci: Blk size:  0x00000200 | Blk cnt:  0x00000400
>> [  738.740892] mmc0: sdhci: Argument:  0x01af6800 | Trn mode: 0x00000023
>> [  738.747330] mmc0: sdhci: Present:   0x01fd8009 | Host ctl: 0x00000031
>> [  738.753767] mmc0: sdhci: Power:     0x00000002 | Blk gap:  0x00000080
>> [  738.760204] mmc0: sdhci: Wake-up:   0x00000008 | Clock:    0x0000000f
>> [  738.766642] mmc0: sdhci: Timeout:   0x0000008f | Int stat: 0x00004000
>> [  738.773079] mmc0: sdhci: Int enab:  0x007f1003 | Sig enab: 0x007f1003
>> [  738.779517] mmc0: sdhci: AC12 err:  0x00000000 | Slot int: 0x00000502
>> [  738.785955] mmc0: sdhci: Caps:      0x07eb0000 | Caps_1:   0x8000b407
>> [  738.792392] mmc0: sdhci: Cmd:       0x00002d12 | Max curr: 0x00ffffff
>> [  738.798829] mmc0: sdhci: Resp[0]:   0x00000c00 | Resp[1]:  0xffffffff
>> [  738.805266] mmc0: sdhci: Resp[2]:   0x328f5903 | Resp[3]:  0x00d02700
>> [  738.811703] mmc0: sdhci: Host ctl2: 0x00000008
>> [  738.816144] mmc0: sdhci: ADMA Err:  0x00000000 | ADMA Ptr: 0x00000000
>> [  738.822579] mmc0: sdhci: ============================================
>> [  748.881580] mmc0: Timeout waiting for hardware interrupt.
>> ......
>>
>>
>>> +
>>> +        host->cqe_recovery_notifier = mmc_cqe_recovery_notifier;
>>> +    }
>>> +
>>>       blk_queue_prep_rq(mq->queue, mmc_prep_request);
>>>       queue_flag_set_unlocked(QUEUE_FLAG_NONROT, mq->queue);
>>>       queue_flag_clear_unlocked(QUEUE_FLAG_ADD_RANDOM, mq-
>>>> queue); @@ -280,9 +543,9 @@ int mmc_init_queue(struct mmc_queue *mq,
>>> struct mmc_card *card,
>>>
>>>       sema_init(&mq->thread_sem, 1);
>>>
>>> -    mq->thread = kthread_run(mmc_queue_thread, mq, "mmcqd/%d%s",
>>> -        host->index, subname ? subname : "");
>>> -
>>> +    mq->thread = kthread_run(use_cqe ? mmc_cqe_thread :
>>> mmc_queue_thread,
>>> +                 mq, "mmcqd/%d%s", host->index,
>>> +                 subname ? subname : "");
>>>       if (IS_ERR(mq->thread)) {
>>>           ret = PTR_ERR(mq->thread);
>>>           goto cleanup_queue;
>>> diff --git a/drivers/mmc/core/queue.h b/drivers/mmc/core/queue.h index
>>> 361b46408e0f..8e9273d977c0 100644
>>> --- a/drivers/mmc/core/queue.h
>>> +++ b/drivers/mmc/core/queue.h
>>> @@ -7,6 +7,20 @@
>>>   #include <linux/mmc/core.h>
>>>   #include <linux/mmc/host.h>
>>>
>>> +enum mmc_issued {
>>> +    MMC_REQ_STARTED,
>>> +    MMC_REQ_BUSY,
>>> +    MMC_REQ_FAILED_TO_START,
>>> +    MMC_REQ_FINISHED,
>>> +};
>>> +
>>> +enum mmc_issue_type {
>>> +    MMC_ISSUE_SYNC,
>>> +    MMC_ISSUE_DCMD,
>>> +    MMC_ISSUE_ASYNC,
>>> +    MMC_ISSUE_MAX,
>>> +};
>>> +
>>>   static inline struct mmc_queue_req *req_to_mmc_queue_req(struct request
>>> *rq)  {
>>>       return blk_mq_rq_to_pdu(rq);
>>> @@ -53,6 +67,7 @@ struct mmc_queue_req {
>>>       int            drv_op_result;
>>>       struct mmc_blk_ioc_data    **idata;
>>>       unsigned int        ioc_count;
>>> +    int            retries;
>>>   };
>>>
>>>   struct mmc_queue {
>>> @@ -70,10 +85,17 @@ struct mmc_queue {
>>>        * associated mmc_queue_req data.
>>>        */
>>>       int            qcnt;
>>> +    /* Following are defined for a Command Queue Engine */
>>> +    int            cqe_in_flight[MMC_ISSUE_MAX];
>>> +    unsigned int        cqe_busy;
>>> +    bool            cqe_recovery_needed;
>>> +    bool            cqe_in_recovery;
>>> +#define MMC_CQE_DCMD_BUSY    BIT(0)
>>> +#define MMC_CQE_QUEUE_FULL    BIT(1)
>>>   };
>>>
>>>   extern int mmc_init_queue(struct mmc_queue *, struct mmc_card *,
>>> spinlock_t *,
>>> -              const char *);
>>> +              const char *, int);
>>>   extern void mmc_cleanup_queue(struct mmc_queue *);  extern void
>>> mmc_queue_suspend(struct mmc_queue *);  extern void
>>> mmc_queue_resume(struct mmc_queue *); @@ -85,4 +107,22 @@ extern
>>> unsigned int mmc_queue_map_sg(struct mmc_queue *,
>>>
>>>   extern int mmc_access_rpmb(struct mmc_queue *);
>>>
>>> +void mmc_cqe_kick_queue(struct mmc_queue *mq);
>>> +
>>> +enum mmc_issue_type mmc_cqe_issue_type(struct mmc_host *host,
>>> +                       struct request *req);
>>> +
>>> +static inline int mmc_cqe_tot_in_flight(struct mmc_queue *mq) {
>>> +    return mq->cqe_in_flight[MMC_ISSUE_SYNC] +
>>> +           mq->cqe_in_flight[MMC_ISSUE_DCMD] +
>>> +           mq->cqe_in_flight[MMC_ISSUE_ASYNC];
>>> +}
>>> +
>>> +static inline int mmc_cqe_qcnt(struct mmc_queue *mq) {
>>> +    return mq->cqe_in_flight[MMC_ISSUE_DCMD] +
>>> +           mq->cqe_in_flight[MMC_ISSUE_ASYNC];
>>> +}
>>> +
>>>   #endif
>>> -- 
>>> 1.9.1
>>
>>
>>
>>
> 
>