Bluetooth doesn't work after S3/S4 or after turning bluetooth on/off several times by toggle key

Bug #1221618 reported by Bruce.Ma
18
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Bluez Utilities
New
Undecided
Unassigned
OEM Priority Project
Invalid
High
Ara Pulido
Precise
Invalid
Undecided
Ara Pulido
bluez (Ubuntu)
Invalid
Undecided
Mathieu Trudel-Lapierre
Precise
Invalid
Undecided
Mathieu Trudel-Lapierre
linux (Ubuntu)
Incomplete
Undecided
Unassigned
Precise
Won't Fix
Undecided
Unassigned

Bug Description

After S3/S4 or turning bluetooth on/off several times by toggle key,
there are many error messages in dmesg. And sometime the bluetooth menu is incomplete.
dmesg:
[ 1117.356421] init: bluetooth main process (3848) terminated with status 1
[ 1117.356506] init: bluetooth main process ended, respawning
[ 1117.399989] init: bluetooth main process (3857) terminated with status 1
[ 1117.400048] init: bluetooth main process ended, respawning

Revision history for this message
Bruce.Ma (bruce.ma) wrote :

This bug is clone from #1217774.

Revision history for this message
Bruce.Ma (bruce.ma) wrote :

The workaround:
Put below code to /etc/init/bluetooth.conf, it make bluetoothd wait 0.5 seconds to startup.
pre-start script
             sleep 0.5
end script

Joey Zheng (jzheng)
Changed in oem-priority:
assignee: nobody → Ara Pulido (apulido)
Revision history for this message
Bruce.Ma (bruce.ma) wrote :

# Root cause, if the bluetooth(kernel module and hardware) didn't finished the initial. Then:
bluez-4.98/src/main.c :
439 int main(int argc, char *argv[])
... ..
511 if (connect_dbus() < 0) {
512 error("Unable to get on D-Bus");
                                   ^^^^^^^^
// The function connect_dbus() will return a non-zero, so will output a log "Unable to get on D-Bus".

385 static int connect_dbus(void)
386 {
387 DBusConnection *conn;
388 DBusError err;
389
390 dbus_error_init(&err);
391
392 conn = g_dbus_setup_bus(DBUS_BUS_SYSTEM, BLUEZ_NAME, &err);
                                ^^^^^^^^^^^^^^^^
393 if (!conn) {
394 if (dbus_error_is_set(&err)) {
                               ^^^^^^^^^^^^^^^
395 g_printerr("D-Bus setup failed: %s\n", err.message);
396 dbus_error_free(&err);
397 return -EIO;
398 }
399 return -EALREADY;

// The value "conn" is non-zero and dbus_error_is_set(&err)) will return none-zero too.

Just restart the bluetooth service by manual, bluetoothd will be startup correctly.
  sudo service bluetooth restart

Ara Pulido (ara)
Changed in oem-priority:
status: New → Confirmed
importance: Undecided → High
Ara Pulido (ara)
Changed in bluez (Ubuntu):
assignee: nobody → Canonical Desktop Team (canonical-desktop-team)
Changed in bluez (Ubuntu Precise):
assignee: nobody → Mathieu Trudel-Lapierre (mathieu-tl)
Revision history for this message
Mathieu Trudel-Lapierre (cyphermox) wrote :

There is absolutely no reason why delaying bluez from starting should affect S3/S4 or killswitches in any normal case, especially not in a relation with dbus, for which the connection is only established on startup.

There *is* a chance where bluetooth would start and not have dbus available, but in this case it would fail immediately on startup, which does not appear to be the issue at hand. That said, since it's a possibility I have a test patch ready.

Please attach a full copy of /var/log/syslog to this bug report so we can see all the messages from bluez and from the kernel bluetooth subsystem. It really seems to me like this is an issue caused by an incomplete initialization of the bluetooth device by the time bluez starts, which is something that really should get fixed in the kernel itself rather than as a workaround in bluez.

Changed in bluez (Ubuntu):
status: New → Incomplete
Changed in bluez (Ubuntu Precise):
status: New → Incomplete
Changed in bluez (Ubuntu):
assignee: Canonical Desktop Team (canonical-desktop-team) → Mathieu Trudel-Lapierre (mathieu-tl)
Revision history for this message
Mathieu Trudel-Lapierre (cyphermox) wrote :

Found a dmesg output from the other bug; I think this is likely a strong hint towards the actual problem:

[ 6135.609315] Bluetooth: hci0 reading Intel fw version command failed (-110)
[ 6137.610607] Bluetooth: hci0 command 0x0c03 tx timeout
[ 6145.595944] Bluetooth: hci0 sending initial HCI reset command failed (-110)

As above, this looks to me like the bluetooth device isn't done initializing by the time bluez tries to talk to it.

Revision history for this message
Brad Figg (brad-figg) wrote : Missing required logs.

This bug is missing log files that will aid in diagnosing the problem. From a terminal window please run:

apport-collect 1221618

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

Changed in linux (Ubuntu):
status: New → Incomplete
Changed in linux (Ubuntu Precise):
status: New → Incomplete
Revision history for this message
Andy Whitcroft (apw) wrote :

By the looks of things this is a platform wherein the actual bluetooth controller is powered off when the kill switch is turned on, and powered up again when the switch is turned off. Thus the controller is initialising when the event is emitted, which starts the bluez which is getting there before it is ready to be used. The fact that a very small timeout before starting it in the upstart job is sufficient to always fix this seem indicative of this. The logical first step would be to make the open for the device in userspace detect the open error and pause and retry a couple of times. Likely we are getting EAGAIN or similar.

Revision history for this message
Tim Gardner (timg-tpi) wrote :

This seems a lot like a user space race. bluez is trying to do stuff with the driver before the firmware is loaded. Is there a way to construct the udev rule such that bluez doesn't get started until after the firmware load is done ?

Revision history for this message
Seth Forshee (sforshee) wrote :

A few observations.

The kernel messages pointed out here aren't come from anything in the precise kernel but rather from modules included via compat-drivers. I found that compat-wireless-3.10-dkms 3.10~rc1~2.20130618.sutton3 is installed, and if that's really coming from an rc1 kernel then there may well be some bug fixes. Releasing anything based off of rc1 code seems like a bad idea.

Since I'm not sure where the source lives for this compat-wireless package I looked at something more recent. Based on that I don't think this is a race between bluez and the kernel (though the fact that adding a delay helps implies that there's likely a race somewhere). There's a setup callback that gets called when userspace opens the device that prints these messages, and that callback tries to issue these commands which are failing and then load the firmware. So it's not a matter of doing stuff before the firmware is loaded, it's that some commands to the device are failing.

There _are_ several commits since 3.10-rc1 dealing with either races (one specifically related to rfkill and device setup) or handling of power on failures. I think we need some testing against the trusty kernel to see if the problem still exists, and if not we can try to find what fixed it. And I'd also like to reiterate the request for logs in comment #6.

Revision history for this message
Bruce.Ma (bruce.ma) wrote :
Revision history for this message
Bruce.Ma (bruce.ma) wrote :

Test this with the latest daily of trusty 3.14.0-031400rc2-generic on T540-1(Kome-T-1), didn't see this issue.

Revision history for this message
Seth Forshee (sforshee) wrote : Re: [Bug 1221618] Re: Bluetooth doesn't work after S3/S4 or after turning bluetooth on/off several times by toggle key

On Wed, Feb 12, 2014 at 06:42:13AM -0000, Bruce.Ma wrote:
> Test this with the latest daily of trusty 3.14.0-031400rc2-generic on
> T540-1(Kome-T-1), didn't see this issue.

In that case you should be able to use the mainline builds to find
roughly where the fix was introduced and then use git bisect to find the
commit which fixes the problem.

Ara Pulido (ara)
Changed in bluez (Ubuntu):
status: Incomplete → Invalid
Changed in bluez (Ubuntu Precise):
status: Incomplete → Invalid
Changed in oem-priority:
status: Confirmed → Invalid
Revision history for this message
Ara Pulido (ara) wrote :

Marking as Invalid in Bluez and oem-priority, based on latest comments (that suggests the problem is in the driver)

Revision history for this message
Adam Lee (adam8157) wrote :

keep watching on this bug but not to reopen it, because:

1, we actually have no public release with that version module.
2, it's fixed in kernel 3.14 as #11.

Revision history for this message
Steve Langasek (vorlon) wrote :

The Precise Pangolin has reached end of life, so this bug will not be fixed for that release

Changed in linux (Ubuntu Precise):
status: Incomplete → Won't Fix
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.