[PATCH] nbd: make starting request more reasonable

[PATCH] nbd: make starting request more reasonable

[Yufen Yu]

Our test robot reported a warning for refcount_dec trying to decrease
value '0'. The reason is that blk_mq_dispatch_rq_list() try to complete
the failed request from nbd driver, while the request have finished in
nbd timeout handle function. The race as following:

CPU1                             CPU2

//req->ref = 1
blk_mq_dispatch_rq_list
nbd_queue_rq
  nbd_handle_cmd
    blk_mq_start_request
                                 blk_mq_check_expired
                                   //req->ref = 2
                                   blk_mq_rq_timed_out
                                     nbd_xmit_timeout
                                       blk_mq_complete_request
                                         //req->ref = 1
                                         refcount_dec_and_test(&req->ref)

                                   refcount_dec_and_test(&req->ref)
                                   //req->ref = 0
                                     __blk_mq_free_request(req)
  ret = BLK_STS_IOERR
blk_mq_end_request
// req->ref = 0, req have been free
refcount_dec_and_test(&rq->ref)

In fact, the bug also have been reported by syzbot:
  https://lkml.org/lkml/2018/12/5/1308

Since the request have been freed by timeout handle, it can be reused
by others. Then, blk_mq_end_request() may get the re-initialized request
and free it, which is unexpected.

To fix the problem, we move blk_mq_start_request() down until the driver
will handle the request actully. If .queue_rq return something error in
preparation phase, timeout handle may don't need. Thus, moving start
request down may be more reasonable. Then, nbd_queue_rq() will not return
BLK_STS_IOERR after starting request.

Reported-by: Hulk Robot <hulkci@huawei.com>
Signed-off-by: Yufen Yu <yuyufen@huawei.com>
---
 drivers/block/nbd.c | 6 ++----
 1 file changed, 2 insertions(+), 4 deletions(-)

diff --git a/drivers/block/nbd.c b/drivers/block/nbd.c
index 78181908f0df..5256e9d02a03 100644
--- a/drivers/block/nbd.c
+++ b/drivers/block/nbd.c
@@ -541,6 +541,8 @@ static int nbd_send_cmd(struct nbd_device *nbd, struct nbd_cmd *cmd, int index)
 		return -EIO;
 	}
 
+	blk_mq_start_request(req);
+
 	if (req->cmd_flags & REQ_FUA)
 		nbd_cmd_flags |= NBD_CMD_FLAG_FUA;
 
@@ -879,7 +881,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
 	if (!refcount_inc_not_zero(&nbd->config_refs)) {
 		dev_err_ratelimited(disk_to_dev(nbd->disk),
 				    "Socks array is empty\n");
-		blk_mq_start_request(req);
 		return -EINVAL;
 	}
 	config = nbd->config;
@@ -888,7 +889,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
 		dev_err_ratelimited(disk_to_dev(nbd->disk),
 				    "Attempted send on invalid socket\n");
 		nbd_config_put(nbd);
-		blk_mq_start_request(req);
 		return -EINVAL;
 	}
 	cmd->status = BLK_STS_OK;
@@ -912,7 +912,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
 			 */
 			sock_shutdown(nbd);
 			nbd_config_put(nbd);
-			blk_mq_start_request(req);
 			return -EIO;
 		}
 		goto again;
@@ -923,7 +922,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
 	 * here so that it gets put _after_ the request that is already on the
 	 * dispatch list.
 	 */
-	blk_mq_start_request(req);
 	if (unlikely(nsock->pending && nsock->pending != req)) {
 		nbd_requeue_cmd(cmd);
 		ret = 0;
-- 
2.16.2.dirty

Re: [PATCH] nbd: make starting request more reasonable

[Josef Bacik]

On 3/3/20 8:08 AM, Yufen Yu wrote:
> Our test robot reported a warning for refcount_dec trying to decrease
> value '0'. The reason is that blk_mq_dispatch_rq_list() try to complete
> the failed request from nbd driver, while the request have finished in
> nbd timeout handle function. The race as following:
> 
> CPU1                             CPU2
> 
> //req->ref = 1
> blk_mq_dispatch_rq_list
> nbd_queue_rq
>    nbd_handle_cmd
>      blk_mq_start_request
>                                   blk_mq_check_expired
>                                     //req->ref = 2
>                                     blk_mq_rq_timed_out
>                                       nbd_xmit_timeout
>                                         blk_mq_complete_request
>                                           //req->ref = 1
>                                           refcount_dec_and_test(&req->ref)
> 
>                                     refcount_dec_and_test(&req->ref)
>                                     //req->ref = 0
>                                       __blk_mq_free_request(req)
>    ret = BLK_STS_IOERR
> blk_mq_end_request
> // req->ref = 0, req have been free
> refcount_dec_and_test(&rq->ref)
> 
> In fact, the bug also have been reported by syzbot:
>    https://lkml.org/lkml/2018/12/5/1308
> 
> Since the request have been freed by timeout handle, it can be reused
> by others. Then, blk_mq_end_request() may get the re-initialized request
> and free it, which is unexpected.
> 
> To fix the problem, we move blk_mq_start_request() down until the driver
> will handle the request actully. If .queue_rq return something error in
> preparation phase, timeout handle may don't need. Thus, moving start
> request down may be more reasonable. Then, nbd_queue_rq() will not return
> BLK_STS_IOERR after starting request.
> 

This won't work, you have to have the request started if you return an error 
because of this in blk_mq_dispatch_rq_list

                 if (unlikely(ret != BLK_STS_OK)) {
                         errors++;
                         blk_mq_end_request(rq, BLK_STS_IOERR);
                         continue;
                 }

The request has to be started before we return an error, pushing it down means 
we have all of these error cases where we haven't started the request.  Thanks,

Josef

Re: [PATCH] nbd: make starting request more reasonable

[Yufen Yu]

Hi, Josef

On 2020/3/4 5:18, Josef Bacik wrote:
> On 3/3/20 8:08 AM, Yufen Yu wrote:
>> Our test robot reported a warning for refcount_dec trying to decrease
>> value '0'. The reason is that blk_mq_dispatch_rq_list() try to complete
>> the failed request from nbd driver, while the request have finished in
>> nbd timeout handle function. The race as following:
>>
>> CPU1                             CPU2
>>
>> //req->ref = 1
>> blk_mq_dispatch_rq_list
>> nbd_queue_rq
>>    nbd_handle_cmd
>>      blk_mq_start_request
>>                                   blk_mq_check_expired
>>                                     //req->ref = 2
>>                                     blk_mq_rq_timed_out
>>                                       nbd_xmit_timeout
>>                                         blk_mq_complete_request
>>                                           //req->ref = 1
>>                                           refcount_dec_and_test(&req->ref)
>>
>>                                     refcount_dec_and_test(&req->ref)
>>                                     //req->ref = 0
>>                                       __blk_mq_free_request(req)
>>    ret = BLK_STS_IOERR
>> blk_mq_end_request
>> // req->ref = 0, req have been free
>> refcount_dec_and_test(&rq->ref)
>>
>> In fact, the bug also have been reported by syzbot:
>>    https://lkml.org/lkml/2018/12/5/1308
>>
>> Since the request have been freed by timeout handle, it can be reused
>> by others. Then, blk_mq_end_request() may get the re-initialized request
>> and free it, which is unexpected.
>>
>> To fix the problem, we move blk_mq_start_request() down until the driver
>> will handle the request actully. If .queue_rq return something error in
>> preparation phase, timeout handle may don't need. Thus, moving start
>> request down may be more reasonable. Then, nbd_queue_rq() will not return
>> BLK_STS_IOERR after starting request.
>>
> 
> This won't work, you have to have the request started if you return an error because of this in blk_mq_dispatch_rq_list >
>                  if (unlikely(ret != BLK_STS_OK)) {
>                          errors++;
>                          blk_mq_end_request(rq, BLK_STS_IOERR);
>                          continue;
>                  }
> 
> The request has to be started before we return an error, pushing it down means we have all of these error cases where we haven't started the reques
IMO, the reason that we need to start request after issuing is for timeout
handle function could trace the request. Here, we should make sure the request
started before the driver process (e.g sock_xmit()). Right?

Before that, if something errors occur in nbd_handle_cmd(), like -EIO, -EINVAL,
that means the request have not actually been handled. So, we also don't need
timeout handler trace it. And the dispatcher function blk_mq_dispatch_rq_list()
or blk_mq_try_issue_directly() is responsible for ending the request.

BTW, other drivers, such as nvme_queue_rq(), scsi_queue_rq(), also start request
before processing it actually. If I get it wrong, please point it out.

Thanks,
Yufen

Re: [PATCH] nbd: make starting request more reasonable

[Yufen Yu]

Ping and Cc to more expert in blk-mq.

On 2020/3/3 21:08, Yufen Yu wrote:
> Our test robot reported a warning for refcount_dec trying to decrease
> value '0'. The reason is that blk_mq_dispatch_rq_list() try to complete
> the failed request from nbd driver, while the request have finished in
> nbd timeout handle function. The race as following:
> 
> CPU1                             CPU2
> 
> //req->ref = 1
> blk_mq_dispatch_rq_list
> nbd_queue_rq
>    nbd_handle_cmd
>      blk_mq_start_request
>                                   blk_mq_check_expired
>                                     //req->ref = 2
>                                     blk_mq_rq_timed_out
>                                       nbd_xmit_timeout
>                                         blk_mq_complete_request
>                                           //req->ref = 1
>                                           refcount_dec_and_test(&req->ref)
> 
>                                     refcount_dec_and_test(&req->ref)
>                                     //req->ref = 0
>                                       __blk_mq_free_request(req)
>    ret = BLK_STS_IOERR
> blk_mq_end_request
> // req->ref = 0, req have been free
> refcount_dec_and_test(&rq->ref)
> 
> In fact, the bug also have been reported by syzbot:
>    https://lkml.org/lkml/2018/12/5/1308
> 
> Since the request have been freed by timeout handle, it can be reused
> by others. Then, blk_mq_end_request() may get the re-initialized request
> and free it, which is unexpected.
> 
> To fix the problem, we move blk_mq_start_request() down until the driver
> will handle the request actully. If .queue_rq return something error in
> preparation phase, timeout handle may don't need. Thus, moving start
> request down may be more reasonable. Then, nbd_queue_rq() will not return
> BLK_STS_IOERR after starting request.
> 
> Reported-by: Hulk Robot <hulkci@huawei.com>
> Signed-off-by: Yufen Yu <yuyufen@huawei.com>
> ---
>   drivers/block/nbd.c | 6 ++----
>   1 file changed, 2 insertions(+), 4 deletions(-)
> 
> diff --git a/drivers/block/nbd.c b/drivers/block/nbd.c
> index 78181908f0df..5256e9d02a03 100644
> --- a/drivers/block/nbd.c
> +++ b/drivers/block/nbd.c
> @@ -541,6 +541,8 @@ static int nbd_send_cmd(struct nbd_device *nbd, struct nbd_cmd *cmd, int index)
>   		return -EIO;
>   	}
>   
> +	blk_mq_start_request(req);
> +
>   	if (req->cmd_flags & REQ_FUA)
>   		nbd_cmd_flags |= NBD_CMD_FLAG_FUA;
>   
> @@ -879,7 +881,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
>   	if (!refcount_inc_not_zero(&nbd->config_refs)) {
>   		dev_err_ratelimited(disk_to_dev(nbd->disk),
>   				    "Socks array is empty\n");
> -		blk_mq_start_request(req);
>   		return -EINVAL;
>   	}
>   	config = nbd->config;
> @@ -888,7 +889,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
>   		dev_err_ratelimited(disk_to_dev(nbd->disk),
>   				    "Attempted send on invalid socket\n");
>   		nbd_config_put(nbd);
> -		blk_mq_start_request(req);
>   		return -EINVAL;
>   	}
>   	cmd->status = BLK_STS_OK;
> @@ -912,7 +912,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
>   			 */
>   			sock_shutdown(nbd);
>   			nbd_config_put(nbd);
> -			blk_mq_start_request(req);
>   			return -EIO;
>   		}
>   		goto again;
> @@ -923,7 +922,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
>   	 * here so that it gets put _after_ the request that is already on the
>   	 * dispatch list.
>   	 */
> -	blk_mq_start_request(req);
>   	if (unlikely(nsock->pending && nsock->pending != req)) {
>   		nbd_requeue_cmd(cmd);
>   		ret = 0;
> 

Re: [PATCH] nbd: make starting request more reasonable

[Ming Lei]

On Mon, Mar 16, 2020 at 08:26:35PM +0800, Yufen Yu wrote:
> Ping and Cc to more expert in blk-mq.
> 
> On 2020/3/3 21:08, Yufen Yu wrote:
> > Our test robot reported a warning for refcount_dec trying to decrease
> > value '0'. The reason is that blk_mq_dispatch_rq_list() try to complete
> > the failed request from nbd driver, while the request have finished in
> > nbd timeout handle function. The race as following:
> > 
> > CPU1                             CPU2
> > 
> > //req->ref = 1
> > blk_mq_dispatch_rq_list
> > nbd_queue_rq
> >    nbd_handle_cmd
> >      blk_mq_start_request
> >                                   blk_mq_check_expired
> >                                     //req->ref = 2
> >                                     blk_mq_rq_timed_out
> >                                       nbd_xmit_timeout

This shouldn't happen in reality, given rq->deadline is just updated
in blk_mq_start_request(), suppose you use the default 30 sec timeout.
How can the race be triggered in so short time?

Could you explain a bit your test case?

> >                                         blk_mq_complete_request
> >                                           //req->ref = 1
> >                                           refcount_dec_and_test(&req->ref)
> > 
> >                                     refcount_dec_and_test(&req->ref)
> >                                     //req->ref = 0
> >                                       __blk_mq_free_request(req)
> >    ret = BLK_STS_IOERR
> > blk_mq_end_request
> > // req->ref = 0, req have been free
> > refcount_dec_and_test(&rq->ref)
> > 
> > In fact, the bug also have been reported by syzbot:
> >    https://lkml.org/lkml/2018/12/5/1308
> > 
> > Since the request have been freed by timeout handle, it can be reused
> > by others. Then, blk_mq_end_request() may get the re-initialized request
> > and free it, which is unexpected.
> > 
> > To fix the problem, we move blk_mq_start_request() down until the driver
> > will handle the request actully. If .queue_rq return something error in
> > preparation phase, timeout handle may don't need. Thus, moving start
> > request down may be more reasonable. Then, nbd_queue_rq() will not return
> > BLK_STS_IOERR after starting request.
> > 
> > Reported-by: Hulk Robot <hulkci@huawei.com>
> > Signed-off-by: Yufen Yu <yuyufen@huawei.com>
> > ---
> >   drivers/block/nbd.c | 6 ++----
> >   1 file changed, 2 insertions(+), 4 deletions(-)
> > 
> > diff --git a/drivers/block/nbd.c b/drivers/block/nbd.c
> > index 78181908f0df..5256e9d02a03 100644
> > --- a/drivers/block/nbd.c
> > +++ b/drivers/block/nbd.c
> > @@ -541,6 +541,8 @@ static int nbd_send_cmd(struct nbd_device *nbd, struct nbd_cmd *cmd, int index)
> >   		return -EIO;
> >   	}
> > +	blk_mq_start_request(req);
> > +
> >   	if (req->cmd_flags & REQ_FUA)
> >   		nbd_cmd_flags |= NBD_CMD_FLAG_FUA;
> > @@ -879,7 +881,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
> >   	if (!refcount_inc_not_zero(&nbd->config_refs)) {
> >   		dev_err_ratelimited(disk_to_dev(nbd->disk),
> >   				    "Socks array is empty\n");
> > -		blk_mq_start_request(req);

I think it is fine to not start request in case of failure, given 
__blk_mq_end_request() doesn't check rq's state.



Thanks,
Ming

Re: [PATCH] nbd: make starting request more reasonable

[Keith Busch]

On Mon, Mar 16, 2020 at 11:30:33PM +0800, Ming Lei wrote:
> On Mon, Mar 16, 2020 at 08:26:35PM +0800, Yufen Yu wrote:
> > > +	blk_mq_start_request(req);
> > > +
> > >   	if (req->cmd_flags & REQ_FUA)
> > >   		nbd_cmd_flags |= NBD_CMD_FLAG_FUA;
> > > @@ -879,7 +881,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
> > >   	if (!refcount_inc_not_zero(&nbd->config_refs)) {
> > >   		dev_err_ratelimited(disk_to_dev(nbd->disk),
> > >   				    "Socks array is empty\n");
> > > -		blk_mq_start_request(req);
> 
> I think it is fine to not start request in case of failure, given 
> __blk_mq_end_request() doesn't check rq's state.

Not only is it fine to not start it, blk-mq expects the low level
driver will not tell it to start a request that the lld doesn't
actually start. A started request should be completed through
blk_mq_complete_request(). Returning an error from your queue_rq()
doesn't do that, and starting it will have blk-mq track the request as
an in-flight request.

Re: [PATCH] nbd: make starting request more reasonable

[Ming Lei]

On Mon, Mar 16, 2020 at 09:02:27AM -0700, Keith Busch wrote:
> On Mon, Mar 16, 2020 at 11:30:33PM +0800, Ming Lei wrote:
> > On Mon, Mar 16, 2020 at 08:26:35PM +0800, Yufen Yu wrote:
> > > > +	blk_mq_start_request(req);
> > > > +
> > > >   	if (req->cmd_flags & REQ_FUA)
> > > >   		nbd_cmd_flags |= NBD_CMD_FLAG_FUA;
> > > > @@ -879,7 +881,6 @@ static int nbd_handle_cmd(struct nbd_cmd *cmd, int index)
> > > >   	if (!refcount_inc_not_zero(&nbd->config_refs)) {
> > > >   		dev_err_ratelimited(disk_to_dev(nbd->disk),
> > > >   				    "Socks array is empty\n");
> > > > -		blk_mq_start_request(req);
> > 
> > I think it is fine to not start request in case of failure, given 
> > __blk_mq_end_request() doesn't check rq's state.
> 
> Not only is it fine to not start it, blk-mq expects the low level
> driver will not tell it to start a request that the lld doesn't
> actually start.

Yeah, in theory, driver should do in this way.

> A started request should be completed through
> blk_mq_complete_request(). Returning an error from your queue_rq()
> doesn't do that, and starting it will have blk-mq track the request as
> an in-flight request.

However, error still can happen when lld is starting to queue the command
to hardware, and there are lots of such usage in drivers. I guess this
way won't be avoided completely.


Thanks,
Ming

Re: [PATCH] nbd: make starting request more reasonable

[Yufen Yu]

Hi, Ming

On 2020/3/16 23:30, Ming Lei wrote:
> On Mon, Mar 16, 2020 at 08:26:35PM +0800, Yufen Yu wrote:
>> Ping and Cc to more expert in blk-mq.
>>
>> On 2020/3/3 21:08, Yufen Yu wrote:
>>> Our test robot reported a warning for refcount_dec trying to decrease
>>> value '0'. The reason is that blk_mq_dispatch_rq_list() try to complete
>>> the failed request from nbd driver, while the request have finished in
>>> nbd timeout handle function. The race as following:
>>>
>>> CPU1                             CPU2
>>>
>>> //req->ref = 1
>>> blk_mq_dispatch_rq_list
>>> nbd_queue_rq
>>>     nbd_handle_cmd
>>>       blk_mq_start_request
>>>                                    blk_mq_check_expired
>>>                                      //req->ref = 2
>>>                                      blk_mq_rq_timed_out
>>>                                        nbd_xmit_timeout
> 
> This shouldn't happen in reality, given rq->deadline is just updated
> in blk_mq_start_request(), suppose you use the default 30 sec timeout.
> How can the race be triggered in so short time? >
> Could you explain a bit your test case?
>
In fact, this is reported by syzkaller. We have not actually test case.
But, I think nbd driver should not start request in case of failure. So fix it.

Thanks,
Yufen