All of lore.kernel.org
 help / color / mirror / Atom feed
* [BUG] Set Powered=true doesn't power up the adapter
@ 2013-05-21  2:07 Alex Deymo
       [not found] ` <CAE6HaMnFF7ym+FCWpVHCi=7=OJZeaS+uiF_qQDKHgpbzLUUu_w@mail.gmail.com>
  2013-05-22  6:45 ` Marcel Holtmann
  0 siblings, 2 replies; 12+ messages in thread
From: Alex Deymo @ 2013-05-21  2:07 UTC (permalink / raw)
  To: linux-bluetooth, keybuk

Hello,

I'm seeing a problem while trying to power on the adapter once in a
while just after reboot. What happens is that sending a dbus call to
power on the adapter doesn't return. You can read a more detailed
description of the bug here [1] but the resume is as follows:

Sending org.freedesktop.DBus.Properties.Set for power up the adapter
doesn't return (dbus timeouts after a while) just after reboot. Is a
very rare bug, but happens from time to time. Restarting bluetoothd
with -n -d to get the logs made it start returning with the error
org.bluez.Error.Failed to the same call. I don't see any HCI command
with btmon while doing this, so I think it's not a firmware issue at
that point (could be some other thing before). From this state, I can
call Set several times to power up the adapter, but doesn't work.
What is interesting is that if instead of sending MGMT_OP_SET_POWERED
from bluetoothd, we try to power up the adapter with hciconfig
(calling ioctl(ctl, HCIDEVUP, hdev) ) the adapter goes up and
everything works fine from there. We are running kernel 3.8, I don't
know if this was already reported in a newer version.

Hope it helps, I'll try to have more debugging information... but it
would be useful it someone can tell me where to look at, since this is
not very easy to reproduce.
Best regards,
Alex.

[1] https://code.google.com/p/chromium/issues/detail?id=239896#c11

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Fwd: [BUG] Set Powered=true doesn't power up the adapter
       [not found] ` <CAE6HaMnFF7ym+FCWpVHCi=7=OJZeaS+uiF_qQDKHgpbzLUUu_w@mail.gmail.com>
@ 2013-05-22  3:55   ` Vinicius Gomes
  2013-05-22  6:47     ` Marcel Holtmann
  0 siblings, 1 reply; 12+ messages in thread
From: Vinicius Gomes @ 2013-05-22  3:55 UTC (permalink / raw)
  To: BlueZ development

Hi Alex,

[forgot to add linux-bluetooth]

On Mon, May 20, 2013 at 11:07 PM, Alex Deymo <deymo@chromium.org> wrote:
> Hello,
>
> I'm seeing a problem while trying to power on the adapter once in a
> while just after reboot. What happens is that sending a dbus call to
> power on the adapter doesn't return. You can read a more detailed
> description of the bug here [1] but the resume is as follows:
>
> Sending org.freedesktop.DBus.Properties.Set for power up the adapter
> doesn't return (dbus timeouts after a while) just after reboot. Is a
> very rare bug, but happens from time to time. Restarting bluetoothd
> with -n -d to get the logs made it start returning with the error
> org.bluez.Error.Failed to the same call. I don't see any HCI command
> with btmon while doing this, so I think it's not a firmware issue at
> that point (could be some other thing before). From this state, I can
> call Set several times to power up the adapter, but doesn't work.
> What is interesting is that if instead of sending MGMT_OP_SET_POWERED
> from bluetoothd, we try to power up the adapter with hciconfig
> (calling ioctl(ctl, HCIDEVUP, hdev) ) the adapter goes up and
> everything works fine from there. We are running kernel 3.8, I don't
> know if this was already reported in a newer version.
>

I can consistently reproduce it:

1. run bluetoothd
2. rfkill block all
3. test-adapter powered on

(current bluetooth-next)

I only got things to work again after a hciconfig up, which makes me
think that the "rfkill block" confuses the kernel (probably) about the
state of the controller.

It is getting late here, I hope this helps, I will try to investigate
it better tomorrow.

> Hope it helps, I'll try to have more debugging information... but it
> would be useful it someone can tell me where to look at, since this is
> not very easy to reproduce.
> Best regards,
> Alex.
>
> [1] https://code.google.com/p/chromium/issues/detail?id=239896#c11
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html


Cheers,
-- 
Vinicius

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-21  2:07 [BUG] Set Powered=true doesn't power up the adapter Alex Deymo
       [not found] ` <CAE6HaMnFF7ym+FCWpVHCi=7=OJZeaS+uiF_qQDKHgpbzLUUu_w@mail.gmail.com>
@ 2013-05-22  6:45 ` Marcel Holtmann
  1 sibling, 0 replies; 12+ messages in thread
From: Marcel Holtmann @ 2013-05-22  6:45 UTC (permalink / raw)
  To: Alex Deymo; +Cc: linux-bluetooth, keybuk

Hi Alex,

> I'm seeing a problem while trying to power on the adapter once in a
> while just after reboot. What happens is that sending a dbus call to
> power on the adapter doesn't return. You can read a more detailed
> description of the bug here [1] but the resume is as follows:
> 
> Sending org.freedesktop.DBus.Properties.Set for power up the adapter
> doesn't return (dbus timeouts after a while) just after reboot. Is a
> very rare bug, but happens from time to time. Restarting bluetoothd
> with -n -d to get the logs made it start returning with the error
> org.bluez.Error.Failed to the same call. I don't see any HCI command
> with btmon while doing this, so I think it's not a firmware issue at
> that point (could be some other thing before). From this state, I can
> call Set several times to power up the adapter, but doesn't work.
> What is interesting is that if instead of sending MGMT_OP_SET_POWERED
> from bluetoothd, we try to power up the adapter with hciconfig
> (calling ioctl(ctl, HCIDEVUP, hdev) ) the adapter goes up and
> everything works fine from there. We are running kernel 3.8, I don't
> know if this was already reported in a newer version.
> 
> Hope it helps, I'll try to have more debugging information... but it
> would be useful it someone can tell me where to look at, since this is
> not very easy to reproduce.

when this happens, can you please enable dynamic debug of the Bluetooth subsystem and try to get the logs from our DBG statements.

Also any chance to set MGMT_DEBUG in that case before restarting bluetoothd. If the mgmt socket gets stuck with a missing response, we might be stuck as well. We had these corner cases in older kernels and worked around them with extra timeouts that protect that section.

Regards

Marcel


^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-22  3:55   ` Fwd: " Vinicius Gomes
@ 2013-05-22  6:47     ` Marcel Holtmann
  2013-05-22 17:22       ` Vinicius Costa Gomes
  0 siblings, 1 reply; 12+ messages in thread
From: Marcel Holtmann @ 2013-05-22  6:47 UTC (permalink / raw)
  To: Vinicius Gomes; +Cc: BlueZ development

Hi Vinicius,

>> I'm seeing a problem while trying to power on the adapter once in a
>> while just after reboot. What happens is that sending a dbus call to
>> power on the adapter doesn't return. You can read a more detailed
>> description of the bug here [1] but the resume is as follows:
>> 
>> Sending org.freedesktop.DBus.Properties.Set for power up the adapter
>> doesn't return (dbus timeouts after a while) just after reboot. Is a
>> very rare bug, but happens from time to time. Restarting bluetoothd
>> with -n -d to get the logs made it start returning with the error
>> org.bluez.Error.Failed to the same call. I don't see any HCI command
>> with btmon while doing this, so I think it's not a firmware issue at
>> that point (could be some other thing before). From this state, I can
>> call Set several times to power up the adapter, but doesn't work.
>> What is interesting is that if instead of sending MGMT_OP_SET_POWERED
>> from bluetoothd, we try to power up the adapter with hciconfig
>> (calling ioctl(ctl, HCIDEVUP, hdev) ) the adapter goes up and
>> everything works fine from there. We are running kernel 3.8, I don't
>> know if this was already reported in a newer version.
>> 
> 
> I can consistently reproduce it:
> 
> 1. run bluetoothd
> 2. rfkill block all
> 3. test-adapter powered on
> 
> (current bluetooth-next)
> 
> I only got things to work again after a hciconfig up, which makes me
> think that the "rfkill block" confuses the kernel (probably) about the
> state of the controller.

what rfkill block does is to bring the controller down and actually refuse to bring it back up until rfkill unblock happens. If we can bring the controller up via mgmt, then we have a bug.

Regards

Marcel


^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-22  6:47     ` Marcel Holtmann
@ 2013-05-22 17:22       ` Vinicius Costa Gomes
  2013-05-22 17:49         ` Marcel Holtmann
  0 siblings, 1 reply; 12+ messages in thread
From: Vinicius Costa Gomes @ 2013-05-22 17:22 UTC (permalink / raw)
  To: Marcel Holtmann; +Cc: BlueZ development

Hi Marcel,

On 08:47 Wed 22 May, Marcel Holtmann wrote:
> Hi Vinicius,
> 
> >> I'm seeing a problem while trying to power on the adapter once in a
> >> while just after reboot. What happens is that sending a dbus call to
> >> power on the adapter doesn't return. You can read a more detailed
> >> description of the bug here [1] but the resume is as follows:
> >> 
> >> Sending org.freedesktop.DBus.Properties.Set for power up the adapter
> >> doesn't return (dbus timeouts after a while) just after reboot. Is a
> >> very rare bug, but happens from time to time. Restarting bluetoothd
> >> with -n -d to get the logs made it start returning with the error
> >> org.bluez.Error.Failed to the same call. I don't see any HCI command
> >> with btmon while doing this, so I think it's not a firmware issue at
> >> that point (could be some other thing before). From this state, I can
> >> call Set several times to power up the adapter, but doesn't work.
> >> What is interesting is that if instead of sending MGMT_OP_SET_POWERED
> >> from bluetoothd, we try to power up the adapter with hciconfig
> >> (calling ioctl(ctl, HCIDEVUP, hdev) ) the adapter goes up and
> >> everything works fine from there. We are running kernel 3.8, I don't
> >> know if this was already reported in a newer version.
> >> 
> > 
> > I can consistently reproduce it:
> > 
> > 1. run bluetoothd
> > 2. rfkill block all
> > 3. test-adapter powered on
> > 
> > (current bluetooth-next)
> > 
> > I only got things to work again after a hciconfig up, which makes me
> > think that the "rfkill block" confuses the kernel (probably) about the
> > state of the controller.
> 
> what rfkill block does is to bring the controller down and actually refuse to bring it back up until rfkill unblock happens. If we can bring the controller up via mgmt, then we have a bug.

Seems that we have just one bug, when the controller is rfkill blocked, mgmt
Set Powered (for example) doesn't return (no Command Complete, no Command
Status).

If I send any Set Powered command after the controller is unblocked, while
there's still one pending command in the queue, this command will fail, and I
won't be able to bring the controller up, unless I force a HCI_RESET command.

So it seems that we need a way to mark an hdev as rfkill blocked.

Does anyone else have any other ideas?

> 
> Regards
> 
> Marcel
> 


Cheers,
-- 
Vinicius

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-22 17:22       ` Vinicius Costa Gomes
@ 2013-05-22 17:49         ` Marcel Holtmann
  2013-05-28  7:13           ` Johan Hedberg
  0 siblings, 1 reply; 12+ messages in thread
From: Marcel Holtmann @ 2013-05-22 17:49 UTC (permalink / raw)
  To: Vinicius Costa Gomes; +Cc: BlueZ development

Hi Vinicius,

>>>> I'm seeing a problem while trying to power on the adapter once in a
>>>> while just after reboot. What happens is that sending a dbus call to
>>>> power on the adapter doesn't return. You can read a more detailed
>>>> description of the bug here [1] but the resume is as follows:
>>>> 
>>>> Sending org.freedesktop.DBus.Properties.Set for power up the adapter
>>>> doesn't return (dbus timeouts after a while) just after reboot. Is a
>>>> very rare bug, but happens from time to time. Restarting bluetoothd
>>>> with -n -d to get the logs made it start returning with the error
>>>> org.bluez.Error.Failed to the same call. I don't see any HCI command
>>>> with btmon while doing this, so I think it's not a firmware issue at
>>>> that point (could be some other thing before). From this state, I can
>>>> call Set several times to power up the adapter, but doesn't work.
>>>> What is interesting is that if instead of sending MGMT_OP_SET_POWERED
>>>> from bluetoothd, we try to power up the adapter with hciconfig
>>>> (calling ioctl(ctl, HCIDEVUP, hdev) ) the adapter goes up and
>>>> everything works fine from there. We are running kernel 3.8, I don't
>>>> know if this was already reported in a newer version.
>>>> 
>>> 
>>> I can consistently reproduce it:
>>> 
>>> 1. run bluetoothd
>>> 2. rfkill block all
>>> 3. test-adapter powered on
>>> 
>>> (current bluetooth-next)
>>> 
>>> I only got things to work again after a hciconfig up, which makes me
>>> think that the "rfkill block" confuses the kernel (probably) about the
>>> state of the controller.
>> 
>> what rfkill block does is to bring the controller down and actually refuse to bring it back up until rfkill unblock happens. If we can bring the controller up via mgmt, then we have a bug.
> 
> Seems that we have just one bug, when the controller is rfkill blocked, mgmt
> Set Powered (for example) doesn't return (no Command Complete, no Command
> Status).
> 
> If I send any Set Powered command after the controller is unblocked, while
> there's still one pending command in the queue, this command will fail, and I
> won't be able to bring the controller up, unless I force a HCI_RESET command.
> 
> So it seems that we need a way to mark an hdev as rfkill blocked.
> 
> Does anyone else have any other ideas?

my wild guess right now is that this is the problem:

	static void hci_power_on(struct work_struct *work)
	{
	        struct hci_dev *hdev = container_of(work, struct hci_dev, power_on);

	        BT_DBG("%s", hdev->name);

	        if (hci_dev_open(hdev->id) < 0)
	                return;

	        if (test_bit(HCI_AUTO_OFF, &hdev->dev_flags))
	                queue_delayed_work(hdev->req_workqueue, &hdev->power_off,
	                                   HCI_AUTO_OFF_TIMEOUT);

	        if (test_and_clear_bit(HCI_SETUP, &hdev->dev_flags))
	                mgmt_index_added(hdev);
	}

In case hci_dev_open() fails and rfkill would be one example for that, we do not return an error back to the mgmt command that originates this power on.

Of course there is the initial adapter power on and there is the mgmt triggered power on. And my guess is that these two are racing against each other.

Regards

Marcel


^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-22 17:49         ` Marcel Holtmann
@ 2013-05-28  7:13           ` Johan Hedberg
  2013-05-28  7:36             ` Marcel Holtmann
  2013-05-29 21:51             ` Alex Deymo
  0 siblings, 2 replies; 12+ messages in thread
From: Johan Hedberg @ 2013-05-28  7:13 UTC (permalink / raw)
  To: Marcel Holtmann; +Cc: Vinicius Costa Gomes, BlueZ development

Hi Marcel,

On Wed, May 22, 2013, Marcel Holtmann wrote:
> > If I send any Set Powered command after the controller is unblocked, while
> > there's still one pending command in the queue, this command will fail, and I
> > won't be able to bring the controller up, unless I force a HCI_RESET command.
> > 
> > So it seems that we need a way to mark an hdev as rfkill blocked.
> > 
> > Does anyone else have any other ideas?
> 
> my wild guess right now is that this is the problem:
> 
> 	static void hci_power_on(struct work_struct *work)
> 	{
> 	        struct hci_dev *hdev = container_of(work, struct hci_dev, power_on);
> 
> 	        BT_DBG("%s", hdev->name);
> 
> 	        if (hci_dev_open(hdev->id) < 0)
> 	                return;
> 
> 	        if (test_bit(HCI_AUTO_OFF, &hdev->dev_flags))
> 	                queue_delayed_work(hdev->req_workqueue, &hdev->power_off,
> 	                                   HCI_AUTO_OFF_TIMEOUT);
> 
> 	        if (test_and_clear_bit(HCI_SETUP, &hdev->dev_flags))
> 	                mgmt_index_added(hdev);
> 	}
> 
> In case hci_dev_open() fails and rfkill would be one example for that,
> we do not return an error back to the mgmt command that originates
> this power on.
> 
> Of course there is the initial adapter power on and there is the mgmt
> triggered power on. And my guess is that these two are racing against
> each other.

It seems you're right about the cause. I just sent a patch to fix it.
With the patch I get this behavior:

jh@qemu~/src/bluez{master}$ sudo rfkill list
0: hci0: Bluetooth
	Soft blocked: no
	Hard blocked: no
jh@qemu~/src/bluez{master}$ sudo rfkill block 0
jh@qemu~/src/bluez{master}$ sudo tools/btmgmt power on
Set Powered for hci0 failed with status 0x03 (Failed)

Johan

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-28  7:13           ` Johan Hedberg
@ 2013-05-28  7:36             ` Marcel Holtmann
  2013-05-28  7:49               ` Johan Hedberg
  2013-05-29 21:51             ` Alex Deymo
  1 sibling, 1 reply; 12+ messages in thread
From: Marcel Holtmann @ 2013-05-28  7:36 UTC (permalink / raw)
  To: Johan Hedberg; +Cc: Vinicius Costa Gomes, BlueZ development

Hi Johan,

>>> If I send any Set Powered command after the controller is unblocked, while
>>> there's still one pending command in the queue, this command will fail, and I
>>> won't be able to bring the controller up, unless I force a HCI_RESET command.
>>> 
>>> So it seems that we need a way to mark an hdev as rfkill blocked.
>>> 
>>> Does anyone else have any other ideas?
>> 
>> my wild guess right now is that this is the problem:
>> 
>> 	static void hci_power_on(struct work_struct *work)
>> 	{
>> 	        struct hci_dev *hdev = container_of(work, struct hci_dev, power_on);
>> 
>> 	        BT_DBG("%s", hdev->name);
>> 
>> 	        if (hci_dev_open(hdev->id) < 0)
>> 	                return;
>> 
>> 	        if (test_bit(HCI_AUTO_OFF, &hdev->dev_flags))
>> 	                queue_delayed_work(hdev->req_workqueue, &hdev->power_off,
>> 	                                   HCI_AUTO_OFF_TIMEOUT);
>> 
>> 	        if (test_and_clear_bit(HCI_SETUP, &hdev->dev_flags))
>> 	                mgmt_index_added(hdev);
>> 	}
>> 
>> In case hci_dev_open() fails and rfkill would be one example for that,
>> we do not return an error back to the mgmt command that originates
>> this power on.
>> 
>> Of course there is the initial adapter power on and there is the mgmt
>> triggered power on. And my guess is that these two are racing against
>> each other.
> 
> It seems you're right about the cause. I just sent a patch to fix it.
> With the patch I get this behavior:
> 
> jh@qemu~/src/bluez{master}$ sudo rfkill list
> 0: hci0: Bluetooth
> 	Soft blocked: no
> 	Hard blocked: no
> jh@qemu~/src/bluez{master}$ sudo rfkill block 0
> jh@qemu~/src/bluez{master}$ sudo tools/btmgmt power on
> Set Powered for hci0 failed with status 0x03 (Failed)

we could be a bit smarter about the error code here. At least when ERFKILL we should return a more descriptive error via mgmt.

Regards

Marcel


^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-28  7:36             ` Marcel Holtmann
@ 2013-05-28  7:49               ` Johan Hedberg
  2013-05-28  8:09                 ` Marcel Holtmann
  0 siblings, 1 reply; 12+ messages in thread
From: Johan Hedberg @ 2013-05-28  7:49 UTC (permalink / raw)
  To: Marcel Holtmann; +Cc: Vinicius Costa Gomes, BlueZ development

Hi Marcel,

On Tue, May 28, 2013, Marcel Holtmann wrote:
> >>> If I send any Set Powered command after the controller is unblocked, while
> >>> there's still one pending command in the queue, this command will fail, and I
> >>> won't be able to bring the controller up, unless I force a HCI_RESET command.
> >>> 
> >>> So it seems that we need a way to mark an hdev as rfkill blocked.
> >>> 
> >>> Does anyone else have any other ideas?
> >> 
> >> my wild guess right now is that this is the problem:
> >> 
> >> 	static void hci_power_on(struct work_struct *work)
> >> 	{
> >> 	        struct hci_dev *hdev = container_of(work, struct hci_dev, power_on);
> >> 
> >> 	        BT_DBG("%s", hdev->name);
> >> 
> >> 	        if (hci_dev_open(hdev->id) < 0)
> >> 	                return;
> >> 
> >> 	        if (test_bit(HCI_AUTO_OFF, &hdev->dev_flags))
> >> 	                queue_delayed_work(hdev->req_workqueue, &hdev->power_off,
> >> 	                                   HCI_AUTO_OFF_TIMEOUT);
> >> 
> >> 	        if (test_and_clear_bit(HCI_SETUP, &hdev->dev_flags))
> >> 	                mgmt_index_added(hdev);
> >> 	}
> >> 
> >> In case hci_dev_open() fails and rfkill would be one example for that,
> >> we do not return an error back to the mgmt command that originates
> >> this power on.
> >> 
> >> Of course there is the initial adapter power on and there is the mgmt
> >> triggered power on. And my guess is that these two are racing against
> >> each other.
> > 
> > It seems you're right about the cause. I just sent a patch to fix it.
> > With the patch I get this behavior:
> > 
> > jh@qemu~/src/bluez{master}$ sudo rfkill list
> > 0: hci0: Bluetooth
> > 	Soft blocked: no
> > 	Hard blocked: no
> > jh@qemu~/src/bluez{master}$ sudo rfkill block 0
> > jh@qemu~/src/bluez{master}$ sudo tools/btmgmt power on
> > Set Powered for hci0 failed with status 0x03 (Failed)
> 
> we could be a bit smarter about the error code here. At least when
> ERFKILL we should return a more descriptive error via mgmt.

I'm fine with that, and I actually left room for it by passing the exact
error to the new mgmt_set_powered_failed function. Would you prefer a
completely new error only used for rfkill or reuse one of our existing
errors. We've e.g. got MGMT_STATUS_REJECTED which could be used for
rfkill and MGMT_STATUS_FAILED for anything else.

Johan

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-28  7:49               ` Johan Hedberg
@ 2013-05-28  8:09                 ` Marcel Holtmann
  0 siblings, 0 replies; 12+ messages in thread
From: Marcel Holtmann @ 2013-05-28  8:09 UTC (permalink / raw)
  To: Johan Hedberg; +Cc: Vinicius Costa Gomes, BlueZ development

Hi Johan,

>>>>> If I send any Set Powered command after the controller is unblocked, while
>>>>> there's still one pending command in the queue, this command will fail, and I
>>>>> won't be able to bring the controller up, unless I force a HCI_RESET command.
>>>>> 
>>>>> So it seems that we need a way to mark an hdev as rfkill blocked.
>>>>> 
>>>>> Does anyone else have any other ideas?
>>>> 
>>>> my wild guess right now is that this is the problem:
>>>> 
>>>> 	static void hci_power_on(struct work_struct *work)
>>>> 	{
>>>> 	        struct hci_dev *hdev = container_of(work, struct hci_dev, power_on);
>>>> 
>>>> 	        BT_DBG("%s", hdev->name);
>>>> 
>>>> 	        if (hci_dev_open(hdev->id) < 0)
>>>> 	                return;
>>>> 
>>>> 	        if (test_bit(HCI_AUTO_OFF, &hdev->dev_flags))
>>>> 	                queue_delayed_work(hdev->req_workqueue, &hdev->power_off,
>>>> 	                                   HCI_AUTO_OFF_TIMEOUT);
>>>> 
>>>> 	        if (test_and_clear_bit(HCI_SETUP, &hdev->dev_flags))
>>>> 	                mgmt_index_added(hdev);
>>>> 	}
>>>> 
>>>> In case hci_dev_open() fails and rfkill would be one example for that,
>>>> we do not return an error back to the mgmt command that originates
>>>> this power on.
>>>> 
>>>> Of course there is the initial adapter power on and there is the mgmt
>>>> triggered power on. And my guess is that these two are racing against
>>>> each other.
>>> 
>>> It seems you're right about the cause. I just sent a patch to fix it.
>>> With the patch I get this behavior:
>>> 
>>> jh@qemu~/src/bluez{master}$ sudo rfkill list
>>> 0: hci0: Bluetooth
>>> 	Soft blocked: no
>>> 	Hard blocked: no
>>> jh@qemu~/src/bluez{master}$ sudo rfkill block 0
>>> jh@qemu~/src/bluez{master}$ sudo tools/btmgmt power on
>>> Set Powered for hci0 failed with status 0x03 (Failed)
>> 
>> we could be a bit smarter about the error code here. At least when
>> ERFKILL we should return a more descriptive error via mgmt.
> 
> I'm fine with that, and I actually left room for it by passing the exact
> error to the new mgmt_set_powered_failed function. Would you prefer a
> completely new error only used for rfkill or reuse one of our existing
> errors. We've e.g. got MGMT_STATUS_REJECTED which could be used for
> rfkill and MGMT_STATUS_FAILED for anything else.

I think a brand new error might be a good idea. RFKILL has always been special.

Regards

Marcel


^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-28  7:13           ` Johan Hedberg
  2013-05-28  7:36             ` Marcel Holtmann
@ 2013-05-29 21:51             ` Alex Deymo
  2013-05-30  2:04               ` Marcel Holtmann
  1 sibling, 1 reply; 12+ messages in thread
From: Alex Deymo @ 2013-05-29 21:51 UTC (permalink / raw)
  To: Marcel Holtmann, Vinicius Costa Gomes, BlueZ development, Johan Hedberg

Hi,

On Tue, May 28, 2013 at 12:13 AM, Johan Hedberg <johan.hedberg@gmail.com> wrote:
>
> On Wed, May 22, 2013, Marcel Holtmann wrote:
> > In case hci_dev_open() fails and rfkill would be one example for that,
> > we do not return an error back to the mgmt command that originates
> > this power on.
> >
> > Of course there is the initial adapter power on and there is the mgmt
> > triggered power on. And my guess is that these two are racing against
> > each other.
>
> It seems you're right about the cause. I just sent a patch to fix it.

I saw the patch about return an error back to the userspace, but still
there is something weird here:
I think I omit an important detail on my first email (ups =D.. but it
was on our linked bug). After reboot, a power up initiated using the
mgmt interface from the bluetoothd will not return, but the previously
connected devices do work. So the adapter is connected to, for
example, a mouse, and after reboot the adapter will be shown as
Powered: False, Set Powered doesn't return, but you can happily move
the bt mouse and it works.

Do you think that the patch about rfkill ( [PATCH] Bluetooth: Fix mgmt
handling of power on failures ) should be enough to fix this issue?
I'm still trying to reproduce the problem with dynamic debug enabled
for bluetooth and launching bluetoothd with MGMT_DEBUG. The machine
keeps rebooting until it faces the problem again... but no luck so far
=(

Thanks,
Alex.

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: [BUG] Set Powered=true doesn't power up the adapter
  2013-05-29 21:51             ` Alex Deymo
@ 2013-05-30  2:04               ` Marcel Holtmann
  0 siblings, 0 replies; 12+ messages in thread
From: Marcel Holtmann @ 2013-05-30  2:04 UTC (permalink / raw)
  To: Alex Deymo; +Cc: Vinicius Costa Gomes, BlueZ development, Johan Hedberg

Hi Alex,

>>> In case hci_dev_open() fails and rfkill would be one example for that,
>>> we do not return an error back to the mgmt command that originates
>>> this power on.
>>> 
>>> Of course there is the initial adapter power on and there is the mgmt
>>> triggered power on. And my guess is that these two are racing against
>>> each other.
>> 
>> It seems you're right about the cause. I just sent a patch to fix it.
> 
> I saw the patch about return an error back to the userspace, but still
> there is something weird here:
> I think I omit an important detail on my first email (ups =D.. but it
> was on our linked bug). After reboot, a power up initiated using the
> mgmt interface from the bluetoothd will not return, but the previously
> connected devices do work. So the adapter is connected to, for
> example, a mouse, and after reboot the adapter will be shown as
> Powered: False, Set Powered doesn't return, but you can happily move
> the bt mouse and it works.
> 
> Do you think that the patch about rfkill ( [PATCH] Bluetooth: Fix mgmt
> handling of power on failures ) should be enough to fix this issue?
> I'm still trying to reproduce the problem with dynamic debug enabled
> for bluetooth and launching bluetoothd with MGMT_DEBUG. The machine
> keeps rebooting until it faces the problem again... but no luck so far
> =(
> 

so hci_dev_open() can return more than just ERFKILL. It can also return EALREADY and other error. So this patch can indeed fix your issue as well. It is just rfkilled devices can reproduce this behavior pretty easily.

What I am thinking you are hitting is a race between the automatic power on (which goes through the same function) and the management power on. We might have a larger issue with a race condition hitting here, but the missing handling of the error is clearly one. There is the hci_req lock serializing the auto power-on and mgmt and so this should not happen, but we might have a bug somewhere else as well.

We might need a bit better instrumentation on being able to debug this. I mentioned this in some threads before, that we might want to have actually proper tracing support. Similar to what mac80211 does. Hint hint ;)

Johan, we might need to check if other errors need to be reported differently and EALREADY handled more gracefully during init of an adapter.

Regards

Marcel


^ permalink raw reply	[flat|nested] 12+ messages in thread

end of thread, other threads:[~2013-05-30  2:04 UTC | newest]

Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2013-05-21  2:07 [BUG] Set Powered=true doesn't power up the adapter Alex Deymo
     [not found] ` <CAE6HaMnFF7ym+FCWpVHCi=7=OJZeaS+uiF_qQDKHgpbzLUUu_w@mail.gmail.com>
2013-05-22  3:55   ` Fwd: " Vinicius Gomes
2013-05-22  6:47     ` Marcel Holtmann
2013-05-22 17:22       ` Vinicius Costa Gomes
2013-05-22 17:49         ` Marcel Holtmann
2013-05-28  7:13           ` Johan Hedberg
2013-05-28  7:36             ` Marcel Holtmann
2013-05-28  7:49               ` Johan Hedberg
2013-05-28  8:09                 ` Marcel Holtmann
2013-05-29 21:51             ` Alex Deymo
2013-05-30  2:04               ` Marcel Holtmann
2013-05-22  6:45 ` Marcel Holtmann

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.