From: Sonny Sasaka <[email protected]>
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;
+ }
+
+ hci_cc_inquiry_cancel(hdev, skb, *status);
break;
case HCI_OP_PERIODIC_INQ:
--
2.17.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
Hi Marcel,
On Tue, Apr 28, 2020 at 2:47 AM Marcel Holtmann <[email protected]> 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
>
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 <[email protected]> wrote:
>
> Hi Marcel,
>
> On Tue, Apr 28, 2020 at 2:47 AM Marcel Holtmann <[email protected]> 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
> >
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
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 <[email protected]> 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
>
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 | 20 ++++++++++++++++++--
1 file changed, 18 insertions(+), 2 deletions(-)
diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
index 3e7badb3ac2d..e8047175de10 100644
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -41,12 +41,28 @@
/* 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);
+ /* 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_dev_err(hdev, "Ignoring error of "
+ "HCI Inquiry Cancel command");
+ status = 0x00;
+ }
+
+ *new_status = status;
+
if (status)
return;
@@ -3036,7 +3052,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:
--
2.17.1
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 <[email protected]> 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 <[email protected]> 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
> >
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 | 20 ++++++++++++++++++--
> 1 file changed, 18 insertions(+), 2 deletions(-)
patch has been applied to bluetooth-next tree.
Regards
Marcel
Thanks, Marcel!
On Wed, May 13, 2020 at 12:35 AM Marcel Holtmann <[email protected]> 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 | 20 ++++++++++++++++++--
> > 1 file changed, 18 insertions(+), 2 deletions(-)
>
> patch has been applied to bluetooth-next tree.
>
> Regards
>
> Marcel
>