diff mbox series

Bluetooth: Handle Inquiry Cancel error after Inquiry Complete

Message ID 20200428051151.14879-1-sonnysasaka@gmail.com (mailing list archive)
State Changes Requested
Delegated to: Marcel Holtmann
Headers show
Series Bluetooth: Handle Inquiry Cancel error after Inquiry Complete | expand

Commit Message

Sonny Sasaka April 28, 2020, 5:11 a.m. UTC
From: Sonny Sasaka <sonnysasaka@chromium.org>

After sending Inquiry Cancel command to the controller, it is possible
that Inquiry Complete event comes before Inquiry Cancel command complete
event. In this case the Inquiry Cancel command will have status of
Command Disallowed since there is no Inquiry session to be cancelled.
This case should not be treated as error, otherwise we can reach an
inconsistent state.

Example of a btmon trace when this happened:

< HCI Command: Inquiry Cancel (0x01|0x0002) plen 0
> HCI Event: Inquiry Complete (0x01) plen 1
        Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 4
      Inquiry Cancel (0x01|0x0002) ncmd 1
        Status: Command Disallowed (0x0c)
---
 net/bluetooth/hci_event.c | 19 +++++++++++++++----
 1 file changed, 15 insertions(+), 4 deletions(-)

Comments

Marcel Holtmann April 28, 2020, 9:47 a.m. UTC | #1
Hi Sonny,

> After sending Inquiry Cancel command to the controller, it is possible
> that Inquiry Complete event comes before Inquiry Cancel command complete
> event. In this case the Inquiry Cancel command will have status of
> Command Disallowed since there is no Inquiry session to be cancelled.
> This case should not be treated as error, otherwise we can reach an
> inconsistent state.
> 
> Example of a btmon trace when this happened:
> 
> < HCI Command: Inquiry Cancel (0x01|0x0002) plen 0
>> HCI Event: Inquiry Complete (0x01) plen 1
>        Status: Success (0x00)
>> HCI Event: Command Complete (0x0e) plen 4
>      Inquiry Cancel (0x01|0x0002) ncmd 1
>        Status: Command Disallowed (0x0c)
> ---
> net/bluetooth/hci_event.c | 19 +++++++++++++++----
> 1 file changed, 15 insertions(+), 4 deletions(-)
> 
> diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> index 966fc543c01d..0f3f7255779f 100644
> --- a/net/bluetooth/hci_event.c
> +++ b/net/bluetooth/hci_event.c
> @@ -42,10 +42,9 @@
> 
> /* Handle HCI Event packets */
> 
> -static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb)
> +static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb,
> +				  u8 status)
> {
> -	__u8 status = *((__u8 *) skb->data);
> -
> 	BT_DBG("%s status 0x%2.2x", hdev->name, status);
> 
> 	if (status)
> @@ -3233,7 +3232,19 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
> 
> 	switch (*opcode) {
> 	case HCI_OP_INQUIRY_CANCEL:
> -		hci_cc_inquiry_cancel(hdev, skb);
> +		/* It is possible that we receive Inquiry Complete event right
> +		 * before we receive Inquiry Cancel Command Complete event, in
> +		 * which case the latter event should have status of Command
> +		 * Disallowed (0x0c). This should not be treated as error, since
> +		 * we actually achieve what Inquiry Cancel wants to achieve,
> +		 * which is to end the last Inquiry session.
> +		 */
> +		if (*status == 0x0c && !test_bit(HCI_INQUIRY, &hdev->flags)) {
> +			BT_DBG("Ignoring error of HCI Inquiry Cancel command");
> +			*status = 0;
> +		}

is there a problem with moving this check into hci_cc_inquiry_cancel? Then we don’t have to play any tricks with an extra parameter that is also included in the skb data struct itself.

I prefer we start using bt_dev_dbg and in this case maybe we just use bt_dev_warn or bt_dev_warn_ratelimited.

Regards

Marcel
Sonny Sasaka April 28, 2020, 5:25 p.m. UTC | #2
Hi Marcel,

On Tue, Apr 28, 2020 at 2:47 AM Marcel Holtmann <marcel@holtmann.org> wrote:
>
> Hi Sonny,
>
> > After sending Inquiry Cancel command to the controller, it is possible
> > that Inquiry Complete event comes before Inquiry Cancel command complete
> > event. In this case the Inquiry Cancel command will have status of
> > Command Disallowed since there is no Inquiry session to be cancelled.
> > This case should not be treated as error, otherwise we can reach an
> > inconsistent state.
> >
> > Example of a btmon trace when this happened:
> >
> > < HCI Command: Inquiry Cancel (0x01|0x0002) plen 0
> >> HCI Event: Inquiry Complete (0x01) plen 1
> >        Status: Success (0x00)
> >> HCI Event: Command Complete (0x0e) plen 4
> >      Inquiry Cancel (0x01|0x0002) ncmd 1
> >        Status: Command Disallowed (0x0c)
> > ---
> > net/bluetooth/hci_event.c | 19 +++++++++++++++----
> > 1 file changed, 15 insertions(+), 4 deletions(-)
> >
> > diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> > index 966fc543c01d..0f3f7255779f 100644
> > --- a/net/bluetooth/hci_event.c
> > +++ b/net/bluetooth/hci_event.c
> > @@ -42,10 +42,9 @@
> >
> > /* Handle HCI Event packets */
> >
> > -static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb)
> > +static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb,
> > +                               u8 status)
> > {
> > -     __u8 status = *((__u8 *) skb->data);
> > -
> >       BT_DBG("%s status 0x%2.2x", hdev->name, status);
> >
> >       if (status)
> > @@ -3233,7 +3232,19 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
> >
> >       switch (*opcode) {
> >       case HCI_OP_INQUIRY_CANCEL:
> > -             hci_cc_inquiry_cancel(hdev, skb);
> > +             /* It is possible that we receive Inquiry Complete event right
> > +              * before we receive Inquiry Cancel Command Complete event, in
> > +              * which case the latter event should have status of Command
> > +              * Disallowed (0x0c). This should not be treated as error, since
> > +              * we actually achieve what Inquiry Cancel wants to achieve,
> > +              * which is to end the last Inquiry session.
> > +              */
> > +             if (*status == 0x0c && !test_bit(HCI_INQUIRY, &hdev->flags)) {
> > +                     BT_DBG("Ignoring error of HCI Inquiry Cancel command");
> > +                     *status = 0;
> > +             }
>
> is there a problem with moving this check into hci_cc_inquiry_cancel? Then we don’t have to play any tricks with an extra parameter that is also included in the skb data struct itself.
I did that the first time, but turns out the updated status code is
needed in the bottom part of this function. So, if we are to move this
logic inside hci_cc_inquiry_cancel, we will need a way to update the
status, for example by having hci_cc_inquiry_cancel return a value, or
accept a pointer for the updated status value. Let me know which way
you prefer.
>
> I prefer we start using bt_dev_dbg and in this case maybe we just use bt_dev_warn or bt_dev_warn_ratelimited.
Ack, I will change BT_DBG to bt_dev_dbg.
>
> Regards
>
> Marcel
>
Sonny Sasaka April 30, 2020, 5:11 p.m. UTC | #3
Hi Marcel,

Could you take another look at my last proposal based on your
suggestion? If we are to move the logic inside hci_cc_inquiry_cancel,
we will need a way to update the status to the caller, for example by
having hci_cc_inquiry_cancel return a value, or accept a pointer for
the updated status value. Let me know which way you prefer.

On Tue, Apr 28, 2020 at 10:25 AM Sonny Sasaka <sonnysasaka@chromium.org> wrote:
>
> Hi Marcel,
>
> On Tue, Apr 28, 2020 at 2:47 AM Marcel Holtmann <marcel@holtmann.org> wrote:
> >
> > Hi Sonny,
> >
> > > After sending Inquiry Cancel command to the controller, it is possible
> > > that Inquiry Complete event comes before Inquiry Cancel command complete
> > > event. In this case the Inquiry Cancel command will have status of
> > > Command Disallowed since there is no Inquiry session to be cancelled.
> > > This case should not be treated as error, otherwise we can reach an
> > > inconsistent state.
> > >
> > > Example of a btmon trace when this happened:
> > >
> > > < HCI Command: Inquiry Cancel (0x01|0x0002) plen 0
> > >> HCI Event: Inquiry Complete (0x01) plen 1
> > >        Status: Success (0x00)
> > >> HCI Event: Command Complete (0x0e) plen 4
> > >      Inquiry Cancel (0x01|0x0002) ncmd 1
> > >        Status: Command Disallowed (0x0c)
> > > ---
> > > net/bluetooth/hci_event.c | 19 +++++++++++++++----
> > > 1 file changed, 15 insertions(+), 4 deletions(-)
> > >
> > > diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> > > index 966fc543c01d..0f3f7255779f 100644
> > > --- a/net/bluetooth/hci_event.c
> > > +++ b/net/bluetooth/hci_event.c
> > > @@ -42,10 +42,9 @@
> > >
> > > /* Handle HCI Event packets */
> > >
> > > -static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb)
> > > +static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb,
> > > +                               u8 status)
> > > {
> > > -     __u8 status = *((__u8 *) skb->data);
> > > -
> > >       BT_DBG("%s status 0x%2.2x", hdev->name, status);
> > >
> > >       if (status)
> > > @@ -3233,7 +3232,19 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
> > >
> > >       switch (*opcode) {
> > >       case HCI_OP_INQUIRY_CANCEL:
> > > -             hci_cc_inquiry_cancel(hdev, skb);
> > > +             /* It is possible that we receive Inquiry Complete event right
> > > +              * before we receive Inquiry Cancel Command Complete event, in
> > > +              * which case the latter event should have status of Command
> > > +              * Disallowed (0x0c). This should not be treated as error, since
> > > +              * we actually achieve what Inquiry Cancel wants to achieve,
> > > +              * which is to end the last Inquiry session.
> > > +              */
> > > +             if (*status == 0x0c && !test_bit(HCI_INQUIRY, &hdev->flags)) {
> > > +                     BT_DBG("Ignoring error of HCI Inquiry Cancel command");
> > > +                     *status = 0;
> > > +             }
> >
> > is there a problem with moving this check into hci_cc_inquiry_cancel? Then we don’t have to play any tricks with an extra parameter that is also included in the skb data struct itself.
> I did that the first time, but turns out the updated status code is
> needed in the bottom part of this function. So, if we are to move this
> logic inside hci_cc_inquiry_cancel, we will need a way to update the
> status, for example by having hci_cc_inquiry_cancel return a value, or
> accept a pointer for the updated status value. Let me know which way
> you prefer.
> >
> > I prefer we start using bt_dev_dbg and in this case maybe we just use bt_dev_warn or bt_dev_warn_ratelimited.
> Ack, I will change BT_DBG to bt_dev_dbg.
> >
> > Regards
> >
> > Marcel
> >
Marcel Holtmann May 5, 2020, 11:42 p.m. UTC | #4
Hi Sonny,

> Could you take another look at my last proposal based on your
> suggestion? If we are to move the logic inside hci_cc_inquiry_cancel,
> we will need a way to update the status to the caller, for example by
> having hci_cc_inquiry_cancel return a value, or accept a pointer for
> the updated status value. Let me know which way you prefer.

maybe something like this (missing comment of course):

--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -42,14 +42,20 @@
 
 /* Handle HCI Event packets */
 
-static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb)
+static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb,
+                                 u8 *new_status)
 {
        __u8 status = *((__u8 *) skb->data);
 
        BT_DBG("%s status 0x%2.2x", hdev->name, status);
 
-       if (status)
+       if (status) {
+               if (!test_bit(HCI_INQUIRY, &hdev->flags) && status == 0x0c) {
+                       BT_DBG("Ignoring error of HCI Inquiry Cancel command");
+                       *new_status = 0x00;
+               }
                return;
+       }
 
        clear_bit(HCI_INQUIRY, &hdev->flags);
        smp_mb__after_atomic(); /* wake_up_bit advises about this barrier */
@@ -3233,7 +3239,7 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
 
        switch (*opcode) {
        case HCI_OP_INQUIRY_CANCEL:
-               hci_cc_inquiry_cancel(hdev, skb);
+               hci_cc_inquiry_cancel(hdev, skb, status);
                break;
 
        case HCI_OP_PERIODIC_INQ:

Regards

Marcel
Sonny Sasaka May 6, 2020, 7:57 p.m. UTC | #5
Hi Marcel,

Please take a look at the modified patch based on your feedback. Thanks.

On Tue, May 5, 2020 at 4:42 PM Marcel Holtmann <marcel@holtmann.org> wrote:
>
> Hi Sonny,
>
> > Could you take another look at my last proposal based on your
> > suggestion? If we are to move the logic inside hci_cc_inquiry_cancel,
> > we will need a way to update the status to the caller, for example by
> > having hci_cc_inquiry_cancel return a value, or accept a pointer for
> > the updated status value. Let me know which way you prefer.
>
> maybe something like this (missing comment of course):
>
> --- a/net/bluetooth/hci_event.c
> +++ b/net/bluetooth/hci_event.c
> @@ -42,14 +42,20 @@
>
>  /* Handle HCI Event packets */
>
> -static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb)
> +static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb,
> +                                 u8 *new_status)
>  {
>         __u8 status = *((__u8 *) skb->data);
>
>         BT_DBG("%s status 0x%2.2x", hdev->name, status);
>
> -       if (status)
> +       if (status) {
> +               if (!test_bit(HCI_INQUIRY, &hdev->flags) && status == 0x0c) {
> +                       BT_DBG("Ignoring error of HCI Inquiry Cancel command");
> +                       *new_status = 0x00;
> +               }
>                 return;
> +       }
>
>         clear_bit(HCI_INQUIRY, &hdev->flags);
>         smp_mb__after_atomic(); /* wake_up_bit advises about this barrier */
> @@ -3233,7 +3239,7 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
>
>         switch (*opcode) {
>         case HCI_OP_INQUIRY_CANCEL:
> -               hci_cc_inquiry_cancel(hdev, skb);
> +               hci_cc_inquiry_cancel(hdev, skb, status);
>                 break;
>
>         case HCI_OP_PERIODIC_INQ:
>
> Regards
>
> Marcel
>
Sonny Sasaka May 12, 2020, 7:34 p.m. UTC | #6
Hi Marcel,

Could you take another look at my latest patch based on your feedback? Thanks.

On Wed, May 6, 2020 at 12:57 PM Sonny Sasaka <sonnysasaka@chromium.org> wrote:
>
> Hi Marcel,
>
> Please take a look at the modified patch based on your feedback. Thanks.
>
> On Tue, May 5, 2020 at 4:42 PM Marcel Holtmann <marcel@holtmann.org> wrote:
> >
> > Hi Sonny,
> >
> > > Could you take another look at my last proposal based on your
> > > suggestion? If we are to move the logic inside hci_cc_inquiry_cancel,
> > > we will need a way to update the status to the caller, for example by
> > > having hci_cc_inquiry_cancel return a value, or accept a pointer for
> > > the updated status value. Let me know which way you prefer.
> >
> > maybe something like this (missing comment of course):
> >
> > --- a/net/bluetooth/hci_event.c
> > +++ b/net/bluetooth/hci_event.c
> > @@ -42,14 +42,20 @@
> >
> >  /* Handle HCI Event packets */
> >
> > -static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb)
> > +static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb,
> > +                                 u8 *new_status)
> >  {
> >         __u8 status = *((__u8 *) skb->data);
> >
> >         BT_DBG("%s status 0x%2.2x", hdev->name, status);
> >
> > -       if (status)
> > +       if (status) {
> > +               if (!test_bit(HCI_INQUIRY, &hdev->flags) && status == 0x0c) {
> > +                       BT_DBG("Ignoring error of HCI Inquiry Cancel command");
> > +                       *new_status = 0x00;
> > +               }
> >                 return;
> > +       }
> >
> >         clear_bit(HCI_INQUIRY, &hdev->flags);
> >         smp_mb__after_atomic(); /* wake_up_bit advises about this barrier */
> > @@ -3233,7 +3239,7 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
> >
> >         switch (*opcode) {
> >         case HCI_OP_INQUIRY_CANCEL:
> > -               hci_cc_inquiry_cancel(hdev, skb);
> > +               hci_cc_inquiry_cancel(hdev, skb, status);
> >                 break;
> >
> >         case HCI_OP_PERIODIC_INQ:
> >
> > Regards
> >
> > Marcel
> >
diff mbox series

Patch

diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
index 966fc543c01d..0f3f7255779f 100644
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -42,10 +42,9 @@ 
 
 /* Handle HCI Event packets */
 
-static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb)
+static void hci_cc_inquiry_cancel(struct hci_dev *hdev, struct sk_buff *skb,
+				  u8 status)
 {
-	__u8 status = *((__u8 *) skb->data);
-
 	BT_DBG("%s status 0x%2.2x", hdev->name, status);
 
 	if (status)
@@ -3233,7 +3232,19 @@  static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
 
 	switch (*opcode) {
 	case HCI_OP_INQUIRY_CANCEL:
-		hci_cc_inquiry_cancel(hdev, skb);
+		/* It is possible that we receive Inquiry Complete event right
+		 * before we receive Inquiry Cancel Command Complete event, in
+		 * which case the latter event should have status of Command
+		 * Disallowed (0x0c). This should not be treated as error, since
+		 * we actually achieve what Inquiry Cancel wants to achieve,
+		 * which is to end the last Inquiry session.
+		 */
+		if (*status == 0x0c && !test_bit(HCI_INQUIRY, &hdev->flags)) {
+			BT_DBG("Ignoring error of HCI Inquiry Cancel command");
+			*status = 0;
+		}
+
+		hci_cc_inquiry_cancel(hdev, skb, *status);
 		break;
 
 	case HCI_OP_PERIODIC_INQ: