2022-11-16 20:35:00

by Mateusz Jończyk

[permalink] [raw]
Subject: [PATCH] Bluetooth: silence a dmesg error message in hci_request.c

On kernel 6.1-rcX, I have been getting the following dmesg error message
on every boot, resume from suspend and rfkill unblock of the Bluetooth
device:

Bluetooth: hci0: HCI_REQ-0xfcf0

After some investigation, it turned out to be caused by
commit dd50a864ffae ("Bluetooth: Delete unreferenced hci_request code")
which modified hci_req_add() in net/bluetooth/hci_request.c to always
print an error message when it is executed. In my case, the function was
executed by msft_set_filter_enable() in net/bluetooth/msft.c, which
provides support for Microsoft vendor opcodes.

As explained by Brian Gix, "the error gets logged because it is using a
deprecated (but still working) mechanism to issue HCI opcodes" [1]. So
this is just a debugging tool to show that a deprecated function is
executed. As such, it should not be included in the mainline kernel.
See for example
commit 771c035372a0 ("deprecate the '__deprecated' attribute warnings entirely and for good")
Additionally, this error message is cryptic and the user is not able to
do anything about it.

[1]
Link: https://lore.kernel.org/lkml/[email protected]/

Fixes: dd50a864ffae ("Bluetooth: Delete unreferenced hci_request code")
Signed-off-by: Mateusz Jończyk <[email protected]>
Cc: Brian Gix <[email protected]>
Cc: Luiz Augusto von Dentz <[email protected]>
Cc: Marcel Holtmann <[email protected]>
Cc: Johan Hedberg <[email protected]>
---
net/bluetooth/hci_request.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/net/bluetooth/hci_request.c b/net/bluetooth/hci_request.c
index 5a0296a4352e..f7e006a36382 100644
--- a/net/bluetooth/hci_request.c
+++ b/net/bluetooth/hci_request.c
@@ -269,7 +269,7 @@ void hci_req_add_ev(struct hci_request *req, u16 opcode, u32 plen,
void hci_req_add(struct hci_request *req, u16 opcode, u32 plen,
const void *param)
{
- bt_dev_err(req->hdev, "HCI_REQ-0x%4.4x", opcode);
+ bt_dev_dbg(req->hdev, "HCI_REQ-0x%4.4x", opcode);
hci_req_add_ev(req, opcode, plen, param, 0);
}


base-commit: 094226ad94f471a9f19e8f8e7140a09c2625abaa
--
2.25.1



2022-11-16 21:06:47

by bluez.test.bot

[permalink] [raw]
Subject: RE: Bluetooth: silence a dmesg error message in hci_request.c

This is automated email and please do not reply to this email!

Dear submitter,

Thank you for submitting the patches to the linux bluetooth mailing list.
This is a CI test results with your patch series:
PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=696145

---Test result---

Test Summary:
CheckPatch FAIL 1.33 seconds
GitLint FAIL 0.82 seconds
SubjectPrefix PASS 0.62 seconds
BuildKernel PASS 34.06 seconds
BuildKernel32 PASS 30.56 seconds
Incremental Build with patchesPASS 45.40 seconds
TestRunner: Setup PASS 510.92 seconds
TestRunner: l2cap-tester PASS 17.45 seconds
TestRunner: iso-tester PASS 16.50 seconds
TestRunner: bnep-tester PASS 6.56 seconds
TestRunner: mgmt-tester PASS 106.15 seconds
TestRunner: rfcomm-tester PASS 10.48 seconds
TestRunner: sco-tester PASS 9.87 seconds
TestRunner: ioctl-tester PASS 11.07 seconds
TestRunner: mesh-tester PASS 7.99 seconds
TestRunner: smp-tester PASS 9.72 seconds
TestRunner: userchan-tester PASS 6.74 seconds

Details
##############################
Test: CheckPatch - FAIL - 1.33 seconds
Run checkpatch.pl script with rule in .checkpatch.conf
Bluetooth: silence a dmesg error message in hci_request.c\WARNING:COMMIT_LOG_LONG_LINE: Possible unwrapped commit description (prefer a maximum 75 chars per line)
#78:
commit 771c035372a0 ("deprecate the '__deprecated' attribute warnings entirely and for good")

total: 0 errors, 1 warnings, 0 checks, 8 lines checked

NOTE: For some of the reported defects, checkpatch may be able to
mechanically convert to the typical style using --fix or --fix-inplace.

/github/workspace/src/13045717.patch has style problems, please review.

NOTE: Ignored message types: UNKNOWN_COMMIT_ID

NOTE: If any of the errors are false positives, please report
them to the maintainer, see CHECKPATCH in MAINTAINERS.


##############################
Test: GitLint - FAIL - 0.82 seconds
Run gitlint with rule in .gitlint
Bluetooth: silence a dmesg error message in hci_request.c
7: B3 Line contains hard tab characters (\t): " Bluetooth: hci0: HCI_REQ-0xfcf0"
21: B1 Line exceeds max length (93>80): "commit 771c035372a0 ("deprecate the '__deprecated' attribute warnings entirely and for good")"
26: B1 Line exceeds max length (92>80): "Link: https://lore.kernel.org/lkml/[email protected]/"




---
Regards,
Linux Bluetooth

2022-11-16 21:41:26

by patchwork-bot+bluetooth

[permalink] [raw]
Subject: Re: [PATCH] Bluetooth: silence a dmesg error message in hci_request.c

Hello:

This patch was applied to bluetooth/bluetooth-next.git (master)
by Luiz Augusto von Dentz <[email protected]>:

On Wed, 16 Nov 2022 21:28:56 +0100 you wrote:
> On kernel 6.1-rcX, I have been getting the following dmesg error message
> on every boot, resume from suspend and rfkill unblock of the Bluetooth
> device:
>
> Bluetooth: hci0: HCI_REQ-0xfcf0
>
> After some investigation, it turned out to be caused by
> commit dd50a864ffae ("Bluetooth: Delete unreferenced hci_request code")
> which modified hci_req_add() in net/bluetooth/hci_request.c to always
> print an error message when it is executed. In my case, the function was
> executed by msft_set_filter_enable() in net/bluetooth/msft.c, which
> provides support for Microsoft vendor opcodes.
>
> [...]

Here is the summary with links:
- Bluetooth: silence a dmesg error message in hci_request.c
https://git.kernel.org/bluetooth/bluetooth-next/c/c3fd63f7fe5a

You are awesome, thank you!
--
Deet-doot-dot, I am a bot.
https://korg.docs.kernel.org/patchwork/pwbot.html



2022-11-17 20:35:47

by Gix, Brian

[permalink] [raw]
Subject: Re: [PATCH] Bluetooth: silence a dmesg error message in hci_request.c

Hi Mateusz,

On Wed, 2022-11-16 at 21:28 +0100, Mateusz Jończyk wrote:
> On kernel 6.1-rcX, I have been getting the following dmesg error
> message
> on every boot, resume from suspend and rfkill unblock of the
> Bluetooth
> device:
>
>         Bluetooth: hci0: HCI_REQ-0xfcf0
>

This has a patch that fixes the usage of the deprecated HCI_REQ
mechanism rather than hiding the fact it is being called, as in this
case.

I am still waiting for someone to give me a "Tested-By:" tag to patch:

[PATCH 1/1] Bluetooth: Convert MSFT filter HCI cmd to hci_sync

Which will also stop the dmesg error. If you could try that patch, and
resend it to the list with a Tested-By tag, it can be applied.

We still want to be allerted to deprecated usage situations.

> After some investigation, it turned out to be caused by
> commit dd50a864ffae ("Bluetooth: Delete unreferenced hci_request
> code")
> which modified hci_req_add() in net/bluetooth/hci_request.c to always
> print an error message when it is executed. In my case, the function
> was
> executed by msft_set_filter_enable() in net/bluetooth/msft.c, which
> provides support for Microsoft vendor opcodes.
>
> As explained by Brian Gix, "the error gets logged because it is using
> a
> deprecated (but still working) mechanism to issue HCI opcodes" [1].
> So
> this is just a debugging tool to show that a deprecated function is
> executed. As such, it should not be included in the mainline kernel.
> See for example
> commit 771c035372a0 ("deprecate the '__deprecated' attribute warnings
> entirely and for good")
> Additionally, this error message is cryptic and the user is not able
> to
> do anything about it.
>
> [1]
> Link:
> https://lore.kernel.org/lkml/[email protected]/
>
> Fixes: dd50a864ffae ("Bluetooth: Delete unreferenced hci_request
> code")
> Signed-off-by: Mateusz Jończyk <[email protected]>
> Cc: Brian Gix <[email protected]>
> Cc: Luiz Augusto von Dentz <[email protected]>
> Cc: Marcel Holtmann <[email protected]>
> Cc: Johan Hedberg <[email protected]>
> ---
>  net/bluetooth/hci_request.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/net/bluetooth/hci_request.c
> b/net/bluetooth/hci_request.c
> index 5a0296a4352e..f7e006a36382 100644
> --- a/net/bluetooth/hci_request.c
> +++ b/net/bluetooth/hci_request.c
> @@ -269,7 +269,7 @@ void hci_req_add_ev(struct hci_request *req, u16
> opcode, u32 plen,
>  void hci_req_add(struct hci_request *req, u16 opcode, u32 plen,
>                  const void *param)
>  {
> -       bt_dev_err(req->hdev, "HCI_REQ-0x%4.4x", opcode);
> +       bt_dev_dbg(req->hdev, "HCI_REQ-0x%4.4x", opcode);
>         hci_req_add_ev(req, opcode, plen, param, 0);
>  }
>  
>
> base-commit: 094226ad94f471a9f19e8f8e7140a09c2625abaa

Regards,
--Brian Gix

2022-11-17 21:29:50

by Mateusz Jończyk

[permalink] [raw]
Subject: Re: [PATCH] Bluetooth: silence a dmesg error message in hci_request.c

W dniu 17.11.2022 o 21:34, Gix, Brian pisze:
> Hi Mateusz,
>
> On Wed, 2022-11-16 at 21:28 +0100, Mateusz Jończyk wrote:
>> On kernel 6.1-rcX, I have been getting the following dmesg error
>> message
>> on every boot, resume from suspend and rfkill unblock of the
>> Bluetooth
>> device:
>>
>>         Bluetooth: hci0: HCI_REQ-0xfcf0
>>
> This has a patch that fixes the usage of the deprecated HCI_REQ
> mechanism rather than hiding the fact it is being called, as in this
> case.
>
> I am still waiting for someone to give me a "Tested-By:" tag to patch:
>
> [PATCH 1/1] Bluetooth: Convert MSFT filter HCI cmd to hci_sync
>
> Which will also stop the dmesg error. If you could try that patch, and
> resend it to the list with a Tested-By tag, it can be applied.

Hello,

I did not receive this patch, as I was not on the CC list; I was not
aware of it. I will test it shortly.

Any guidelines how I should test this functionality? I have a Sony Xperia 10 i4113
mobile phone with LineageOS 19.1 / Android 12L, which according to the spec supports
Bluetooth 5.0. Quick Google search tells me that I should do things like 

        hcitool lescan

to discover the phone, then use gatttool to list the services, etc.

Greetings,

Mateusz


2022-11-17 21:45:10

by Gix, Brian

[permalink] [raw]
Subject: Re: [PATCH] Bluetooth: silence a dmesg error message in hci_request.c

Hi Mateusz,

On Thu, 2022-11-17 at 22:27 +0100, Mateusz Jończyk wrote:
> W dniu 17.11.2022 o 21:34, Gix, Brian pisze:
> > On Wed, 2022-11-16 at 21:28 +0100, Mateusz Jończyk wrote:
> > > On kernel 6.1-rcX, I have been getting the following dmesg error
> > > message
> > > on every boot, resume from suspend and rfkill unblock of the
> > > Bluetooth
> > > device:
> > >
> > >         Bluetooth: hci0: HCI_REQ-0xfcf0
> > >
> > This has a patch that fixes the usage of the deprecated HCI_REQ
> > mechanism rather than hiding the fact it is being called, as in
> > this
> > case.
> >
> > I am still waiting for someone to give me a "Tested-By:" tag to
> > patch:
> >
> > [PATCH 1/1] Bluetooth: Convert MSFT filter HCI cmd to hci_sync
> >
> > Which will also stop the dmesg error. If you could try that patch,
> > and
> > resend it to the list with a Tested-By tag, it can be applied.
>
> Hello,
>
> I did not receive this patch, as I was not on the CC list; I was not
> aware of it. I will test it shortly.
>
> Any guidelines how I should test this functionality? I have a Sony
> Xperia 10 i4113
> mobile phone with LineageOS 19.1 / Android 12L, which according to
> the spec supports
> Bluetooth 5.0. Quick Google search tells me that I should do things
> like 
>
>         hcitool lescan
>

Whatever you were running that produced the

"Bluetooth: hci0: HCI_REQ-0xfcf0"

error in the dmesg log should be sufficient to determine that the error
log is no longer happening. The HCI call is necessary on some
platforms, so the absense of other negative behavior should be
sufficient to verify that the call is still being made. The code flow
itself has not changed, and new coding enforces the HCI command
sequence, so that it is more deterministric than it was with
hci_request. The hci_request mechanism was an asyncronous request.

> to discover the phone, then use gatttool to list the services, etc.
>
> Greetings,
>
> Mateusz
>

2022-11-17 22:20:31

by Luiz Augusto von Dentz

[permalink] [raw]
Subject: Re: [PATCH] Bluetooth: silence a dmesg error message in hci_request.c

Hi,

On Thu, Nov 17, 2022 at 1:45 PM Gix, Brian <[email protected]> wrote:
>
> Hi Mateusz,
>
> On Thu, 2022-11-17 at 22:27 +0100, Mateusz Jończyk wrote:
> > W dniu 17.11.2022 o 21:34, Gix, Brian pisze:
> > > On Wed, 2022-11-16 at 21:28 +0100, Mateusz Jończyk wrote:
> > > > On kernel 6.1-rcX, I have been getting the following dmesg error
> > > > message
> > > > on every boot, resume from suspend and rfkill unblock of the
> > > > Bluetooth
> > > > device:
> > > >
> > > > Bluetooth: hci0: HCI_REQ-0xfcf0
> > > >
> > > This has a patch that fixes the usage of the deprecated HCI_REQ
> > > mechanism rather than hiding the fact it is being called, as in
> > > this
> > > case.
> > >
> > > I am still waiting for someone to give me a "Tested-By:" tag to
> > > patch:
> > >
> > > [PATCH 1/1] Bluetooth: Convert MSFT filter HCI cmd to hci_sync
> > >
> > > Which will also stop the dmesg error. If you could try that patch,
> > > and
> > > resend it to the list with a Tested-By tag, it can be applied.
> >
> > Hello,
> >
> > I did not receive this patch, as I was not on the CC list; I was not
> > aware of it. I will test it shortly.

You can find the patch here:

https://patchwork.kernel.org/project/bluetooth/patch/[email protected]/

> >
> > Any guidelines how I should test this functionality? I have a Sony
> > Xperia 10 i4113
> > mobile phone with LineageOS 19.1 / Android 12L, which according to
> > the spec supports
> > Bluetooth 5.0. Quick Google search tells me that I should do things
> > like
> >
> > hcitool lescan
> >
>
> Whatever you were running that produced the
>
> "Bluetooth: hci0: HCI_REQ-0xfcf0"
>
> error in the dmesg log should be sufficient to determine that the error
> log is no longer happening. The HCI call is necessary on some
> platforms, so the absense of other negative behavior should be
> sufficient to verify that the call is still being made. The code flow
> itself has not changed, and new coding enforces the HCI command
> sequence, so that it is more deterministric than it was with
> hci_request. The hci_request mechanism was an asyncronous request.
>
> > to discover the phone, then use gatttool to list the services, etc.
> >
> > Greetings,
> >
> > Mateusz
> >
>


--
Luiz Augusto von Dentz

2022-11-27 11:08:29

by Mateusz Jończyk

[permalink] [raw]
Subject: Re: [PATCH] Bluetooth: silence a dmesg error message in hci_request.c

W dniu 16.11.2022 o 22:40, [email protected] pisze:
> Hello:
>
> This patch was applied to bluetooth/bluetooth-next.git (master)
> by Luiz Augusto von Dentz <[email protected]>:
>
> On Wed, 16 Nov 2022 21:28:56 +0100 you wrote:
>> On kernel 6.1-rcX, I have been getting the following dmesg error message
>> on every boot, resume from suspend and rfkill unblock of the Bluetooth
>> device:
>>
>> Bluetooth: hci0: HCI_REQ-0xfcf0
>>
>> After some investigation, it turned out to be caused by
>> commit dd50a864ffae ("Bluetooth: Delete unreferenced hci_request code")
>> which modified hci_req_add() in net/bluetooth/hci_request.c to always
>> print an error message when it is executed. In my case, the function was
>> executed by msft_set_filter_enable() in net/bluetooth/msft.c, which
>> provides support for Microsoft vendor opcodes.
>>
>> [...]
> Here is the summary with links:
> - Bluetooth: silence a dmesg error message in hci_request.c
> https://git.kernel.org/bluetooth/bluetooth-next/c/c3fd63f7fe5a
>
> You are awesome, thank you!

Hello,

Thank you. I would like to ask: is this patch going to be merged for kernel 6.1?

The error message that this patch silences will no doubt confuse some users
if it will be released in Linux 6.1.0.

Greetings,

Mateusz