diff mbox series

[4/6] ufs: Fix a race condition in the tracing code

Message ID 20191224220248.30138-5-bvanassche@acm.org (mailing list archive)
State Accepted
Headers show
Series Six UFS patches | expand

Commit Message

Bart Van Assche Dec. 24, 2019, 10:02 p.m. UTC
Starting execution of a command before tracing a command may cause the
completion handler to free data while it is being traced. Fix this race
by tracing a command before it is submitted.

Cc: Bean Huo <beanhuo@micron.com>
Cc: Can Guo <cang@codeaurora.org>
Cc: Avri Altman <avri.altman@wdc.com>
Cc: Stanley Chu <stanley.chu@mediatek.com>
Cc: Tomas Winkler <tomas.winkler@intel.com>
Signed-off-by: Bart Van Assche <bvanassche@acm.org>
---
 drivers/scsi/ufs/ufshcd.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Comments

Can Guo Dec. 25, 2019, 10:59 a.m. UTC | #1
On 2019-12-25 06:02, Bart Van Assche wrote:
> Starting execution of a command before tracing a command may cause the
> completion handler to free data while it is being traced. Fix this race
> by tracing a command before it is submitted.
> 
> Cc: Bean Huo <beanhuo@micron.com>
> Cc: Can Guo <cang@codeaurora.org>
> Cc: Avri Altman <avri.altman@wdc.com>
> Cc: Stanley Chu <stanley.chu@mediatek.com>
> Cc: Tomas Winkler <tomas.winkler@intel.com>
> Signed-off-by: Bart Van Assche <bvanassche@acm.org>
> ---
>  drivers/scsi/ufs/ufshcd.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
> index 80b028ba39e9..4d9bb1932b39 100644
> --- a/drivers/scsi/ufs/ufshcd.c
> +++ b/drivers/scsi/ufs/ufshcd.c
> @@ -1875,12 +1875,12 @@ void ufshcd_send_command(struct ufs_hba *hba,
> unsigned int task_tag)
>  {
>  	hba->lrb[task_tag].issue_time_stamp = ktime_get();
>  	hba->lrb[task_tag].compl_time_stamp = ktime_set(0, 0);
> +	ufshcd_add_command_trace(hba, task_tag, "send");

How about moving it after __set_bit(task_tag, &hba->outstanding_reqs);?

Thanks,

Can Guo.

>  	ufshcd_clk_scaling_start_busy(hba);
>  	__set_bit(task_tag, &hba->outstanding_reqs);
>  	ufshcd_writel(hba, 1 << task_tag, REG_UTP_TRANSFER_REQ_DOOR_BELL);
>  	/* Make sure that doorbell is committed immediately */
>  	wmb();
> -	ufshcd_add_command_trace(hba, task_tag, "send");
>  }
> 
>  /**
Bart Van Assche Dec. 26, 2019, 5:35 p.m. UTC | #2
On 12/25/19 2:59 AM, Can Guo wrote:
> On 2019-12-25 06:02, Bart Van Assche wrote:
>> Starting execution of a command before tracing a command may cause the
>> completion handler to free data while it is being traced. Fix this race
>> by tracing a command before it is submitted.
>>
>> Cc: Bean Huo <beanhuo@micron.com>
>> Cc: Can Guo <cang@codeaurora.org>
>> Cc: Avri Altman <avri.altman@wdc.com>
>> Cc: Stanley Chu <stanley.chu@mediatek.com>
>> Cc: Tomas Winkler <tomas.winkler@intel.com>
>> Signed-off-by: Bart Van Assche <bvanassche@acm.org>
>> ---
>>  drivers/scsi/ufs/ufshcd.c | 2 +-
>>  1 file changed, 1 insertion(+), 1 deletion(-)
>>
>> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
>> index 80b028ba39e9..4d9bb1932b39 100644
>> --- a/drivers/scsi/ufs/ufshcd.c
>> +++ b/drivers/scsi/ufs/ufshcd.c
>> @@ -1875,12 +1875,12 @@ void ufshcd_send_command(struct ufs_hba *hba,
>> unsigned int task_tag)
>>  {
>>      hba->lrb[task_tag].issue_time_stamp = ktime_get();
>>      hba->lrb[task_tag].compl_time_stamp = ktime_set(0, 0);
>> +    ufshcd_add_command_trace(hba, task_tag, "send");
> 
> How about moving it after __set_bit(task_tag, &hba->outstanding_reqs);?
> 
> Thanks,
> 
> Can Guo.
> 
>>      ufshcd_clk_scaling_start_busy(hba);
>>      __set_bit(task_tag, &hba->outstanding_reqs);
>>      ufshcd_writel(hba, 1 << task_tag, REG_UTP_TRANSFER_REQ_DOOR_BELL);
>>      /* Make sure that doorbell is committed immediately */
>>      wmb();
>> -    ufshcd_add_command_trace(hba, task_tag, "send");
>>  }

Hi Can,

As far as I can see ufshcd_add_command_trace() does not read 
hba->outstanding_reqs so calling ufshcd_add_command_trace() before 
changing outstanding_reqs should be fine.

The order chosen in the posted patch should minimize energy usage of the 
UFS controller, namely by calling the tracing function before starting 
clock scaling.

Thanks,

Bart.
Alim Akhtar Dec. 27, 2019, 1:21 a.m. UTC | #3
On Wed, Dec 25, 2019 at 3:34 AM Bart Van Assche <bvanassche@acm.org> wrote:
>
> Starting execution of a command before tracing a command may cause the
> completion handler to free data while it is being traced. Fix this race
> by tracing a command before it is submitted.
>
> Cc: Bean Huo <beanhuo@micron.com>
> Cc: Can Guo <cang@codeaurora.org>
> Cc: Avri Altman <avri.altman@wdc.com>
> Cc: Stanley Chu <stanley.chu@mediatek.com>
> Cc: Tomas Winkler <tomas.winkler@intel.com>
> Signed-off-by: Bart Van Assche <bvanassche@acm.org>
> ---
Reviewed-by: Alim Akhtar <alim.akhtar@samsung.com>
>  drivers/scsi/ufs/ufshcd.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
> index 80b028ba39e9..4d9bb1932b39 100644
> --- a/drivers/scsi/ufs/ufshcd.c
> +++ b/drivers/scsi/ufs/ufshcd.c
> @@ -1875,12 +1875,12 @@ void ufshcd_send_command(struct ufs_hba *hba, unsigned int task_tag)
>  {
>         hba->lrb[task_tag].issue_time_stamp = ktime_get();
>         hba->lrb[task_tag].compl_time_stamp = ktime_set(0, 0);
> +       ufshcd_add_command_trace(hba, task_tag, "send");
>         ufshcd_clk_scaling_start_busy(hba);
>         __set_bit(task_tag, &hba->outstanding_reqs);
>         ufshcd_writel(hba, 1 << task_tag, REG_UTP_TRANSFER_REQ_DOOR_BELL);
>         /* Make sure that doorbell is committed immediately */
>         wmb();
> -       ufshcd_add_command_trace(hba, task_tag, "send");
>  }
>
>  /**
Can Guo Dec. 27, 2019, 5:50 a.m. UTC | #4
On 2019-12-27 01:35, Bart Van Assche wrote:
> On 12/25/19 2:59 AM, Can Guo wrote:
>> On 2019-12-25 06:02, Bart Van Assche wrote:
>>> Starting execution of a command before tracing a command may cause 
>>> the
>>> completion handler to free data while it is being traced. Fix this 
>>> race
>>> by tracing a command before it is submitted.
>>> 
>>> Cc: Bean Huo <beanhuo@micron.com>
>>> Cc: Can Guo <cang@codeaurora.org>
>>> Cc: Avri Altman <avri.altman@wdc.com>
>>> Cc: Stanley Chu <stanley.chu@mediatek.com>
>>> Cc: Tomas Winkler <tomas.winkler@intel.com>
>>> Signed-off-by: Bart Van Assche <bvanassche@acm.org>
>>> ---
>>>  drivers/scsi/ufs/ufshcd.c | 2 +-
>>>  1 file changed, 1 insertion(+), 1 deletion(-)
>>> 
>>> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
>>> index 80b028ba39e9..4d9bb1932b39 100644
>>> --- a/drivers/scsi/ufs/ufshcd.c
>>> +++ b/drivers/scsi/ufs/ufshcd.c
>>> @@ -1875,12 +1875,12 @@ void ufshcd_send_command(struct ufs_hba *hba,
>>> unsigned int task_tag)
>>>  {
>>>      hba->lrb[task_tag].issue_time_stamp = ktime_get();
>>>      hba->lrb[task_tag].compl_time_stamp = ktime_set(0, 0);
>>> +    ufshcd_add_command_trace(hba, task_tag, "send");
>> 
>> How about moving it after __set_bit(task_tag, 
>> &hba->outstanding_reqs);?
>> 
>> Thanks,
>> 
>> Can Guo.
>> 
>>>      ufshcd_clk_scaling_start_busy(hba);
>>>      __set_bit(task_tag, &hba->outstanding_reqs);
>>>      ufshcd_writel(hba, 1 << task_tag, 
>>> REG_UTP_TRANSFER_REQ_DOOR_BELL);
>>>      /* Make sure that doorbell is committed immediately */
>>>      wmb();
>>> -    ufshcd_add_command_trace(hba, task_tag, "send");
>>>  }
> 
> Hi Can,
> 
> As far as I can see ufshcd_add_command_trace() does not read
> hba->outstanding_reqs so calling ufshcd_add_command_trace() before
> changing outstanding_reqs should be fine.
> 
> The order chosen in the posted patch should minimize energy usage of
> the UFS controller, namely by calling the tracing function before
> starting clock scaling.
> 
> Thanks,
> 
> Bart.

True.

One concern regards this change is that since we move the 
ufshcd_add_command_trace() before ringing doorbell, in tracing log,
we will lose the info/status of this specific tag in doorbell register.

Usually, with the old code, after we collect the tracing log, we can
tell whether the doorbell bit was set/rung correctly in doorbell
register or not for an specific tag/task, because it is an important
sign of whether HW had actually accepted the task on that tag. It
is really helpful sometime if things go wrong.

Any good ways to keep the doorbell info as before?

Thanks,

Can Guo.
diff mbox series

Patch

diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index 80b028ba39e9..4d9bb1932b39 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -1875,12 +1875,12 @@  void ufshcd_send_command(struct ufs_hba *hba, unsigned int task_tag)
 {
 	hba->lrb[task_tag].issue_time_stamp = ktime_get();
 	hba->lrb[task_tag].compl_time_stamp = ktime_set(0, 0);
+	ufshcd_add_command_trace(hba, task_tag, "send");
 	ufshcd_clk_scaling_start_busy(hba);
 	__set_bit(task_tag, &hba->outstanding_reqs);
 	ufshcd_writel(hba, 1 << task_tag, REG_UTP_TRANSFER_REQ_DOOR_BELL);
 	/* Make sure that doorbell is committed immediately */
 	wmb();
-	ufshcd_add_command_trace(hba, task_tag, "send");
 }
 
 /**