| Message ID | 20240624121158.21354-1-peter.wang@mediatek.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | [v2] ufs: core: fix ufshcd_abort_all racing issue | expand |
On 6/24/24 5:11 AM, peter.wang@mediatek.com wrote: > [ ... ] In this patch there are two call traces, two fixes tags and two code changes. Please split this patch into two patches with each one call trace, one Fixes: tag and one code change. Additionally, please include a changelog when posting a second or later version. > diff --git a/drivers/ufs/core/ufs-mcq.c b/drivers/ufs/core/ufs-mcq.c > index 8944548c30fa..3b2e5bcb08a7 100644 > --- a/drivers/ufs/core/ufs-mcq.c > +++ b/drivers/ufs/core/ufs-mcq.c > @@ -512,8 +512,9 @@ int ufshcd_mcq_sq_cleanup(struct ufs_hba *hba, int task_tag) > return -ETIMEDOUT; > > if (task_tag != hba->nutrs - UFSHCD_NUM_RESERVED) { > - if (!cmd) > - return -EINVAL; > + /* Should return 0 if cmd is already complete by irq */ > + if (!cmd || !ufshcd_cmd_inflight(cmd)) > + return 0; > hwq = ufshcd_mcq_req_to_hwq(hba, scsi_cmd_to_rq(cmd)); > } else { > hwq = hba->dev_cmd_queue; Does the call trace show that blk_mq_unique_tag() tries to dereference address 0x194? If so, how is this possible? There are only two lrbp->cmd assignments in the UFS driver. These assignments either assign a valid SCSI command pointer or NULL. Even after a SCSI command has been completed, the SCSI command pointer remains valid. So how can an invalid pointer be passed to blk_mq_unique_tag()? Please root-cause this issue instead of posting a code change that reduces a race window without closing the race window completely. Thanks, Bart.
On Mon, 2024-06-24 at 11:01 -0700, Bart Van Assche wrote: > > External email : Please do not click links or open attachments until > you have verified the sender or the content. > On 6/24/24 5:11 AM, peter.wang@mediatek.com wrote: > > [ ... ] > In this patch there are two call traces, two fixes tags and two code > changes. Please split this patch into two patches with each one call > trace, one Fixes: tag and one code change. Additionally, please > include > a changelog when posting a second or later version. > Hi Bart, Will split this patch into two patches and add changelog next version, thanks. > > diff --git a/drivers/ufs/core/ufs-mcq.c b/drivers/ufs/core/ufs- > mcq.c > > index 8944548c30fa..3b2e5bcb08a7 100644 > > --- a/drivers/ufs/core/ufs-mcq.c > > +++ b/drivers/ufs/core/ufs-mcq.c > > @@ -512,8 +512,9 @@ int ufshcd_mcq_sq_cleanup(struct ufs_hba *hba, > int task_tag) > > return -ETIMEDOUT; > > > > if (task_tag != hba->nutrs - UFSHCD_NUM_RESERVED) { > > -if (!cmd) > > -return -EINVAL; > > +/* Should return 0 if cmd is already complete by irq */ > > +if (!cmd || !ufshcd_cmd_inflight(cmd)) > > +return 0; > > hwq = ufshcd_mcq_req_to_hwq(hba, scsi_cmd_to_rq(cmd)); > > } else { > > hwq = hba->dev_cmd_queue; > > Does the call trace show that blk_mq_unique_tag() tries to > dereference > address 0x194? If so, how is this possible? There are > only two lrbp->cmd assignments in the UFS driver. These assignments > either assign a valid SCSI command pointer or NULL. Even after a SCSI > command has been completed, the SCSI command pointer remains valid. > So > how can an invalid pointer be passed to blk_mq_unique_tag()? Please > root-cause this issue instead of posting a code change that reduces a > race window without closing the race window completely. > > Thanks, > > Bart. > blk_mq_unique_tag() tries to dereference address 0x194, and it is null. Beacuse ISR end this IO by scsi_done, free request will be called and set mq_hctx null. The call path is scsi_done -> scsi_done_internal -> blk_mq_complete_request -> scsi_complete -> scsi_finish_command -> scsi_io_completion -> scsi_end_request -> __blk_mq_end_request -> blk_mq_free_request -> __blk_mq_free_request And blk_mq_unique_tag will access mq_hctx then get null pointer error. Please reference https://elixir.bootlin.com/linux/latest/source/block/blk-mq.c#L713 https://elixir.bootlin.com/linux/latest/source/block/blk-mq-tag.c#L680 So, the root-casue is very simple, free request then get hwq. This patch only check if reqesut not free(inflight) then get hwq. Thought it still have racing winodw, but it is better then do nothing, right? Or, maybe we get all cq_lock before get hwq to close the racing window. But the code may ugly, how do you think? Thanks. Peter
On 6/25/24 1:29 AM, Peter Wang (王信友) wrote: > On Mon, 2024-06-24 at 11:01 -0700, Bart Van Assche wrote: >> On 6/24/24 5:11 AM, peter.wang@mediatek.com wrote: >>> diff --git a/drivers/ufs/core/ufs-mcq.c b/drivers/ufs/core/ufs- >> mcq.c >>> index 8944548c30fa..3b2e5bcb08a7 100644 >>> --- a/drivers/ufs/core/ufs-mcq.c >>> +++ b/drivers/ufs/core/ufs-mcq.c >>> @@ -512,8 +512,9 @@ int ufshcd_mcq_sq_cleanup(struct ufs_hba *hba, >> int task_tag) >>> return -ETIMEDOUT; >>> >>> if (task_tag != hba->nutrs - UFSHCD_NUM_RESERVED) { >>> -if (!cmd) >>> -return -EINVAL; >>> +/* Should return 0 if cmd is already complete by irq */ >>> +if (!cmd || !ufshcd_cmd_inflight(cmd)) >>> +return 0; >>> hwq = ufshcd_mcq_req_to_hwq(hba, scsi_cmd_to_rq(cmd)); >>> } else { >>> hwq = hba->dev_cmd_queue; >> >> Does the call trace show that blk_mq_unique_tag() tries to >> dereference >> address 0x194? If so, how is this possible? There are >> only two lrbp->cmd assignments in the UFS driver. These assignments >> either assign a valid SCSI command pointer or NULL. Even after a SCSI >> command has been completed, the SCSI command pointer remains valid. >> So >> how can an invalid pointer be passed to blk_mq_unique_tag()? Please >> root-cause this issue instead of posting a code change that reduces a >> race window without closing the race window completely. > > blk_mq_unique_tag() tries to dereference address 0x194, and it is null. > Beacuse ISR end this IO by scsi_done, free request will be called and > set mq_hctx null. > The call path is > scsi_done -> scsi_done_internal -> blk_mq_complete_request -> > scsi_complete -> > scsi_finish_command -> scsi_io_completion -> scsi_end_request -> > __blk_mq_end_request -> > blk_mq_free_request -> __blk_mq_free_request > > And blk_mq_unique_tag will access mq_hctx then get null pointer error. > Please reference > https://elixir.bootlin.com/linux/latest/source/block/blk-mq.c#L713 > https://elixir.bootlin.com/linux/latest/source/block/blk-mq-tag.c#L680 > > So, the root-casue is very simple, free request then get hwq. > This patch only check if reqesut not free(inflight) then get hwq. > Thought it still have racing winodw, but it is better then do nothing, > right? > Or, maybe we get all cq_lock before get hwq to close the racing window. > But the code may ugly, how do you think? Please include a full root cause analysis when reposting fixes for the reported crashes. It is not clear to me how it is possible that an invalid pointer is passed to blk_mq_unique_tag() (0x194). As I mentioned in my previous email, freeing a request does not modify the request pointer and does not modify the SCSI command pointer either. As one can derive from the blk_mq_alloc_rqs() call stack, memory for struct request and struct scsi_cmnd is allocated at request queue allocation time and is not freed until the request queue is freed. Hence, for a given tag, neither the request pointer nor the SCSI command pointer changes as long as a request queue exists. Hence my request for an explanation how it is possible that an invalid pointer was passed to blk_mq_unique_tag(). Thanks, Bart.
On Tue, 2024-06-25 at 09:42 -0700, Bart Van Assche wrote: > > > Please include a full root cause analysis when reposting fixes for > the > reported crashes. It is not clear to me how it is possible that an > invalid pointer is passed to blk_mq_unique_tag() (0x194). As I > mentioned > in my previous email, freeing a request does not modify the request > pointer and does not modify the SCSI command pointer either. As one > can > derive from the blk_mq_alloc_rqs() call stack, memory for struct > request > and struct scsi_cmnd is allocated at request queue allocation time > and > is not freed until the request queue is freed. Hence, for a given > tag, > neither the request pointer nor the SCSI command pointer changes as > long > as a request queue exists. Hence my request for an explanation how it > is > possible that an invalid pointer was passed to blk_mq_unique_tag(). > > Thanks, > > Bart. > Hi Bart, Sorry I have not explain root-cause clearly. I will add more clear root-cause analyze next version. And it is not an invalid pointer is passed to blk_mq_unique_tag(), I means blk_mq_unique_tag function try access null pointer. It is differnt and cause misunderstanding. The null pinter blk_mq_unique_tag try access is: rq->mq_hctx(NULL)->queue_num. The racing flow is: Thread A ufshcd_err_handler step 1 ufshcd_cmd_inflight(true) step 3 ufshcd_mcq_req_to_hwq blk_mq_unique_tag rq->mq_hctx->queue_num step 5 Thread B ufs_mtk_mcq_intr(cq complete ISR) step 2 scsi_done ... __blk_mq_free_request rq->mq_hctx = NULL; step 4 Thanks. Peter
On 6/25/24 8:56 PM, Peter Wang (王信友) wrote: > Sorry I have not explain root-cause clearly. > I will add more clear root-cause analyze next version. > > And it is not an invalid pointer is passed to blk_mq_unique_tag(), > I means blk_mq_unique_tag function try access null pointer. > It is differnt and cause misunderstanding. > > The null pinter blk_mq_unique_tag try access is: > rq->mq_hctx(NULL)->queue_num. > > The racing flow is: > > Thread A > ufshcd_err_handler step 1 > ufshcd_cmd_inflight(true) step 3 > ufshcd_mcq_req_to_hwq > blk_mq_unique_tag > rq->mq_hctx->queue_num step 5 > > Thread B > ufs_mtk_mcq_intr(cq complete ISR) step 2 > scsi_done > ... > __blk_mq_free_request > rq->mq_hctx = NULL; step 4 How about surrounding the blk_mq_unique_tag() call with atomic_inc_not_zero(&req->ref) / atomic_dec(&req->ref)? Thanks, Bart.
On 2024/6/26 11:56, Peter Wang (王信友) wrote: > On Tue, 2024-06-25 at 09:42 -0700, Bart Van Assche wrote: >> >> >> Please include a full root cause analysis when reposting fixes for >> the >> reported crashes. It is not clear to me how it is possible that an >> invalid pointer is passed to blk_mq_unique_tag() (0x194). As I >> mentioned >> in my previous email, freeing a request does not modify the request >> pointer and does not modify the SCSI command pointer either. As one >> can >> derive from the blk_mq_alloc_rqs() call stack, memory for struct >> request >> and struct scsi_cmnd is allocated at request queue allocation time >> and >> is not freed until the request queue is freed. Hence, for a given >> tag, >> neither the request pointer nor the SCSI command pointer changes as >> long >> as a request queue exists. Hence my request for an explanation how it >> is >> possible that an invalid pointer was passed to blk_mq_unique_tag(). >> >> Thanks, >> >> Bart. >> > > Hi Bart, > > Sorry I have not explain root-cause clearly. > I will add more clear root-cause analyze next version. > > And it is not an invalid pointer is passed to blk_mq_unique_tag(), > I means blk_mq_unique_tag function try access null pointer. > It is differnt and cause misunderstanding. > > The null pinter blk_mq_unique_tag try access is: > rq->mq_hctx(NULL)->queue_num. > Hi Peter, What is queue_num's offset of blk_mq_hw_ctx in your machine? gdb vmlinux (gdb) print /x (int)&((struct blk_mq_hw_ctx *)0)->queue_num $5 = 0x164 I read your descriptions and wondered a same race flow as you described following. But I found the offset mismatch, if the racing flow is correct, then the address accessed in blk_mq_unique_tag() should be 0x164, not 0x194. Maybe the offset is different between our machine? What's more, if the racing flow is correct, I did not get how your changes can address this racing flow. > The racing flow is: > > Thread A > ufshcd_err_handler step 1 > ufshcd_cmd_inflight(true) step 3 > ufshcd_mcq_req_to_hwq > blk_mq_unique_tag > rq->mq_hctx->queue_num step 5 > > Thread B > ufs_mtk_mcq_intr(cq complete ISR) step 2 > scsi_done > ... > __blk_mq_free_request > rq->mq_hctx = NULL; step 4 > > Thanks. > Peter > > > >
On 2024/6/27 1:13, Bart Van Assche wrote: > On 6/25/24 8:56 PM, Peter Wang (王信友) wrote: >> Sorry I have not explain root-cause clearly. >> I will add more clear root-cause analyze next version. >> >> And it is not an invalid pointer is passed to blk_mq_unique_tag(), >> I means blk_mq_unique_tag function try access null pointer. >> It is differnt and cause misunderstanding. >> >> The null pinter blk_mq_unique_tag try access is: >> rq->mq_hctx(NULL)->queue_num. >> >> The racing flow is: >> >> Thread A >> ufshcd_err_handler step 1 >> ufshcd_cmd_inflight(true) step 3 >> ufshcd_mcq_req_to_hwq >> blk_mq_unique_tag >> rq->mq_hctx->queue_num step 5 >> >> Thread B >> ufs_mtk_mcq_intr(cq complete ISR) step 2 >> scsi_done >> ... >> __blk_mq_free_request >> rq->mq_hctx = NULL; step 4 > > How about surrounding the blk_mq_unique_tag() call with > atomic_inc_not_zero(&req->ref) / atomic_dec(&req->ref)? > Hi Bart, A small wonder, then should we append __blk_mq_free_request() if req->ref decreased to 0 like following? if (req_ref_put_and_test(rq)) __blk_mq_free_request(rq); > Thanks, > > Bart. >
On Thu, 2024-06-27 at 15:59 +0800, Wenchao Hao wrote: > > Hi Peter, > > What is queue_num's offset of blk_mq_hw_ctx in your machine? > > gdb vmlinux > > (gdb) print /x (int)&((struct blk_mq_hw_ctx *)0)->queue_num > $5 = 0x164 > > I read your descriptions and wondered a same race flow as you > described > following. But I found the offset mismatch, if the racing flow is > correct, > then the address accessed in blk_mq_unique_tag() should be 0x164, not > 0x194. > Maybe the offset is different between our machine? > > What's more, if the racing flow is correct, I did not get how your > changes > can address this racing flow. > > Hi Wenchao Hao, Yes, our queue_num's offset of blk_mq_hw_ctx is 0x194. Our kernel version is: Linux version 6.1.68 I think the offset is different by kernel version. (gdb) print /x (int)&((struct blk_mq_hw_ctx *)0)->queue_num $1 = 0x194 And yes, it only shorten the race window of step3 and step5. Reduce the probability of step 4 appearing between step 3 and step 5. Thanks. Peter
On Thu, 2024-06-27 at 17:19 +0800, Wenchao Hao wrote: > > > Hi Bart, > > A small wonder, then should we append __blk_mq_free_request() if > req->ref decreased to 0 like following? > > if (req_ref_put_and_test(rq)) > __blk_mq_free_request(rq); > > > > Thanks, > > > > Bart. > > > Hi Bart and Wenchao Hao, It could be have side effect if we surrounding the blk_mq_unique_tag() call with atomic_inc_not_zero(&req->ref) / atomic_dec(&req->ref)? Beacuse __blk_mq_free_request stll have other finish job to. This is a chicken-and-egg problem. We need to acquire a lock to know which hwq it is, but we need to know which hwq it is to acquire the lock. Therefore, to resolve this dilemma, perhaps we should just take all the hwq locks indiscriminately? Thanks. Peter
On 6/27/24 3:59 AM, Peter Wang (王信友) wrote: > This is a chicken-and-egg problem. We need to acquire a lock to know > which hwq it is, but we need to know which hwq it is to acquire the > lock. Therefore, to resolve this dilemma, perhaps we should just take > all the hwq locks indiscriminately? How about the (untested) patch below? Thanks, Bart. diff --git a/drivers/ufs/core/ufs-mcq.c b/drivers/ufs/core/ufs-mcq.c index aa119746ee92..c5d327ba253f 100644 --- a/drivers/ufs/core/ufs-mcq.c +++ b/drivers/ufs/core/ufs-mcq.c @@ -105,16 +105,15 @@ EXPORT_SYMBOL_GPL(ufshcd_mcq_config_mac); * @hba: per adapter instance * @req: pointer to the request to be issued * - * Return: the hardware queue instance on which the request would - * be queued. + * Return: the hardware queue instance on which the request will be or has been + * queued. %NULL if the request has already been freed. */ struct ufs_hw_queue *ufshcd_mcq_req_to_hwq(struct ufs_hba *hba, struct request *req) { - u32 utag = blk_mq_unique_tag(req); - u32 hwq = blk_mq_unique_tag_to_hwq(utag); + struct blk_mq_hw_ctx *hctx = READ_ONCE(rq->mq_hctx); - return &hba->uhq[hwq]; + return hctx ? &hba->uhq[hctx->queue_num] : NULL; } /** @@ -547,6 +546,8 @@ int ufshcd_mcq_sq_cleanup(struct ufs_hba *hba, int task_tag) if (!cmd) return -EINVAL; hwq = ufshcd_mcq_req_to_hwq(hba, scsi_cmd_to_rq(cmd)); + if (!hwq) + return -EINVAL; } else { hwq = hba->dev_cmd_queue; }
On 2024/6/27 18:58, Peter Wang (王信友) wrote: > On Thu, 2024-06-27 at 15:59 +0800, Wenchao Hao wrote: >> >> Hi Peter, >> >> What is queue_num's offset of blk_mq_hw_ctx in your machine? >> >> gdb vmlinux >> >> (gdb) print /x (int)&((struct blk_mq_hw_ctx *)0)->queue_num >> $5 = 0x164 >> >> I read your descriptions and wondered a same race flow as you >> described >> following. But I found the offset mismatch, if the racing flow is >> correct, >> then the address accessed in blk_mq_unique_tag() should be 0x164, not >> 0x194. >> Maybe the offset is different between our machine? >> >> What's more, if the racing flow is correct, I did not get how your >> changes >> can address this racing flow. >> >> > > Hi Wenchao Hao, > > Yes, our queue_num's offset of blk_mq_hw_ctx is 0x194. > Our kernel version is: Linux version 6.1.68 > I think the offset is different by kernel version. > > (gdb) print /x (int)&((struct blk_mq_hw_ctx *)0)->queue_num > $1 = 0x194 > > And yes, it only shorten the race window of step3 and step5. > Reduce the probability of step 4 appearing between step 3 and step 5. > > Hi Peter, Thanks for your reply, I understand the issue now. > Thanks. > Peter
> struct ufs_hw_queue *ufshcd_mcq_req_to_hwq(struct ufs_hba *hba, > struct request *req) > { > -u32 utag = blk_mq_unique_tag(req); > -u32 hwq = blk_mq_unique_tag_to_hwq(utag); > +struct blk_mq_hw_ctx *hctx = READ_ONCE(rq->mq_hctx); > > -return &hba->uhq[hwq]; > +return hctx ? &hba->uhq[hctx->queue_num] : NULL; > } > Hi Bart, Yes, it could be work, thanks. > /** > @@ -547,6 +546,8 @@ int ufshcd_mcq_sq_cleanup(struct ufs_hba *hba, > int > task_tag) > if (!cmd) > return -EINVAL; > hwq = ufshcd_mcq_req_to_hwq(hba, scsi_cmd_to_rq(cmd)); > +if (!hwq) > +return -EINVAL; > Should retrun 0, beacuse hwq null means tag is done by ISR. We don't need cleanup sq now. Thanks. Peter > } else { > hwq = hba->dev_cmd_queue; > } >
diff --git a/drivers/ufs/core/ufs-mcq.c b/drivers/ufs/core/ufs-mcq.c index 8944548c30fa..3b2e5bcb08a7 100644 --- a/drivers/ufs/core/ufs-mcq.c +++ b/drivers/ufs/core/ufs-mcq.c @@ -512,8 +512,9 @@ int ufshcd_mcq_sq_cleanup(struct ufs_hba *hba, int task_tag) return -ETIMEDOUT; if (task_tag != hba->nutrs - UFSHCD_NUM_RESERVED) { - if (!cmd) - return -EINVAL; + /* Should return 0 if cmd is already complete by irq */ + if (!cmd || !ufshcd_cmd_inflight(cmd)) + return 0; hwq = ufshcd_mcq_req_to_hwq(hba, scsi_cmd_to_rq(cmd)); } else { hwq = hba->dev_cmd_queue; diff --git a/drivers/ufs/core/ufshcd.c b/drivers/ufs/core/ufshcd.c index e5e9da61f15d..e8bca62ceed8 100644 --- a/drivers/ufs/core/ufshcd.c +++ b/drivers/ufs/core/ufshcd.c @@ -6455,11 +6455,12 @@ static bool ufshcd_abort_one(struct request *rq, void *priv) /* Release cmd in MCQ mode if abort succeeds */ if (is_mcq_enabled(hba) && (*ret == 0)) { - hwq = ufshcd_mcq_req_to_hwq(hba, scsi_cmd_to_rq(lrbp->cmd)); - spin_lock_irqsave(&hwq->cq_lock, flags); - if (ufshcd_cmd_inflight(lrbp->cmd)) + if (ufshcd_cmd_inflight(lrbp->cmd)) { + hwq = ufshcd_mcq_req_to_hwq(hba, scsi_cmd_to_rq(lrbp->cmd)); + spin_lock_irqsave(&hwq->cq_lock, flags); ufshcd_release_scsi_cmd(hba, lrbp); - spin_unlock_irqrestore(&hwq->cq_lock, flags); + spin_unlock_irqrestore(&hwq->cq_lock, flags); + } } return *ret == 0;