Re: [PATCH v2 1/4] Bluetooth: Keep MSFT ext info throughout a hci_dev's life cycle

[Miao-chen Chou <mcchou@chromium.org>]

Hi Marcel,

On Fri, Dec 18, 2020 at 1:39 PM Marcel Holtmann <marcel@holtmann.org> wrote:
>
> Hi Miao-chen,
>
> > This moves msft_do_close() from hci_dev_do_close() to
> > hci_unregister_dev() to avoid clearing MSFT extension info. This also
> > avoids retrieving MSFT info upon every msft_do_open() if MSFT extension
> > has been initialized.
>
> what is the actual benefit of this?
>
> It is fundamentally one extra HCI command and that one does no harm. You are trying to outsmart the hdev->setup vs the !hdev->setup case. I don’t think this is a good idea.
>
> So unless I see a real argument why we want to do this, I am leaving this patch out. And on a side note, I named these function exactly this way so they are symmetric with hci_dev_do_{open,close}.
>
> Regards
>
> Marcel
>
Thanks for pointing that out. I totally agree that it's not a wise
thing to outsmart the symmetric hci_dev_do_{open,close}. However, the
following two cases justify why we need this change.
(1) The current symmetric calls to msft_do{open,close} in
hci_dev_do_{open,close} cause incorrect MSFT features during
bluetoothd start-up. After the kernel powers on the controller to
register the hci_dev, it performs hci_dev_do_close() which call
msft_do_close() and MSFT data gets wiped out. And then during the
startup of bluetoothd, Adv Monitor Manager relies on reading the MSFT
features from the kernel to present the feature set of the controller
to D-Bus clients. However, the power state of the controller is off
during the init of D-Bus interfaces. As a result, invalid MSFT
features are returned by the kernel, since it was previously wiped out
due to hci_dev_do_close().
(2) Assuming bluetoothd has started, and users can be toggling the
power state of the adapter. Powering off the adapter invokes
hci_power_off()->hci_dev_do_close()->msft_do_close(), and MSFT
features get wiped out. During powered-off period, D-Bus client can
still add/remove monitor from the kernel, and the kernel needs to
issue corresponding MSFT HCI commands to the controller. However, the
MSFT opcode has been reset and invalid.

And here is the trace (for case 1 above) that I captured without this change.

2021-01-15T01:34:43.800155Z INFO kernel: [    2.754911] Bluetooth:
hci_power_on() @@ call hci_dev_do_open
2021-01-15T01:34:45.145025Z INFO kernel: [    4.272376] Bluetooth:
hci_dev_do_open() @@ call msft_do_open
2021-01-15T01:34:45.145050Z INFO kernel: [    4.272382] Bluetooth:
msft_do_open() @@
2021-01-15T01:34:45.146020Z INFO kernel: [    4.273139] Bluetooth:
read_supported_features() @@ features 000000000000003f
2021-01-15T01:34:47.176410Z INFO kernel: [    6.303439] Bluetooth:
hci_power_off() @@ call hci_dev_do_close
2021-01-15T01:34:47.189020Z INFO kernel: [    6.316152] Bluetooth:
hci_dev_do_close() @@ call msft_do_close
2021-01-15T01:34:47.189032Z INFO kernel: [    6.316158] Bluetooth:
msft_do_close() @@
2021-01-15T01:34:47.957401Z INFO bluetoothd[2591]: Bluetooth daemon 5.54
// skip some logs here
2021-01-15T01:34:48.004066Z INFO bluetoothd[2591]: Bluetooth
management interface 1.14 initialized
2021-01-15T01:34:48.167703Z INFO bluetoothd[2591]: @@ call
btd_adv_monitor_manager_create
2021-01-15T01:34:48.167832Z INFO bluetoothd[2591]: @@ call
MGMT_OP_READ_ADV_MONITOR_FEATURES
2021-01-15T01:34:48.167886Z INFO bluetoothd[2591]: Battery Provider
Manager created
2021-01-15T01:34:48.171924Z INFO bluetoothd[2591]: @@ features
supported_features 00000000 enabled_features 00000000
2021-01-15T01:34:48.172088Z INFO kernel: [    7.299305] Bluetooth:
hci_power_on() @@ call hci_dev_do_open
2021-01-15T01:34:48.172083Z INFO bluetoothd[2591]: Adv Monitor Manager
created with supported features:0x00000000, enabled
features:0x00000000, max number of supported monitors:32, max number
of supported patterns:16
2021-01-15T01:34:48.207800Z INFO bluetoothd[2591]: Endpoint
registered: sender=:1.52 path=/org/chromium/Cras/Bluetooth/A2DPSource
2021-01-15T01:34:48.212522Z INFO bluetoothd[2591]: Player registered:
sender=:1.52 path=/org/chromium/Cras/Bluetooth/DefaultPlayer
2021-01-15T01:34:48.214813Z INFO bluetoothd[2591]: BlueZ log level is set to 1
2021-01-15T01:34:48.230035Z INFO kernel: [    7.357118] Bluetooth:
hci_dev_do_open() @@ call msft_do_open
2021-01-15T01:34:48.230063Z INFO kernel: [    7.357124] Bluetooth:
msft_do_open() @@
2021-01-15T01:34:48.231027Z INFO kernel: [    7.358131] Bluetooth:
read_supported_features() @@ features 000000000000003f
2021-01-15T01:34:48.248967Z INFO bluetoothd[2591]: adapter
/org/bluez/hci0 has been enabled
2021-01-15T01:34:49.176198Z INFO bluetoothd[2591]: adapter
/org/bluez/hci0 set power to 1

Thanks,
Miao