DebuggingBluetooth

Differences between revisions 13 and 14
Revision 13 as of 2016-10-31 22:05:44
Size: 11331
Editor: kzapalowicz
Comment: rewrite of the information provided as per request on the hague sprint
Revision 14 as of 2016-12-31 21:51:06
Size: 10479
Editor: penalvch
Comment: 1) Chg user redact & share. Shared attachments far larger chance being addressed vs. sent privately. 2) RM manual bug filing missing apport attachments unhelpful. 3) Misc presentation fixes.
Deletions are marked like this. Additions are marked like this.
Line 2: Line 2:

||<tablestyle="float:right; font-size: 0.9em; background:#F1F1ED;margin: 0 0 1em 1em;" style="padding:2.0em;"><<TableOfContents>>||
Line 5: Line 7:
'''If you're going to attach the log files mentioned below be warned that those might include private information like phone numbers. If you're asked to share such log files you're free to not do this or share them with the asking person on a more private way than through launchpad/irc/.. ''' '''If you're going to attach the log files mentioned below, be warned that they might include private information like phone numbers. If you're asked to share such log files, please redact any information you don't feel comfortable sharing and post the results to your bug report.'''
Line 7: Line 9:
= Reporting the bug on Launchpad =
Line 8: Line 11:
Ubuntu bluetooth bugs are tracked on Launchpad. When filing a report, please ensure one is using apport. For more on this, please see [[https://help.ubuntu.com/community/ReportingBugs|here]].
Line 9: Line 13:
= Reporting a bug = The package to use with apport can be:
 *[[https://launchpad.net/ubuntu/+source/bluez|bluez]] - Issues in the bluetooth protcol stack
 *[[https://launchpad.net/ubuntu/+source/linux|linux]] - Hardware dependent issues
 * Issues could be caused by the desktop environment (GNOME, KDE, etc.), or its Bluetooth applications.
 * If any doubts, feel free to file it under bluez and it will be rerouted as applicable.
Line 11: Line 19:
Bugs for Ubuntu are tracked on Launchpad and Bluetooth has its own area there. Please use the following link to report Bluetooth bugs: Once one has reported the bug to Launchpad, it is vital to include the required information that will allow developers to address your issue.
Line 13: Line 21:
= Information required to include in a bug report =
Line 14: Line 23:
https://bugs.launchpad.net/ubuntu/+source/bluez/+filebug

== What is necessary to include ==

Please remember that the better the bug is described the easier it is for the developers to figure out what is happening and find the solution. The things to include would be:


 * List the devices involved. Exact model numbers if available are helpful.
 * Which Bluetooth version do all involved devices support
 * The bluez version and kernel version on your Ubuntu based device
 * Necessary log files in debug mode (see the next section for the list of flies)


The last item is crucial as it can unveil the system status at the moment the fault has occurred. There will be more on this in the following section but in short the log files that should be attached are:

== System information ==

Apart from a good bug description it is also a good idea to provide a basic information about the Ubuntu system that is involved. The interesting details are:


 1. Bluetooth stack version
 2. The Linux kernel version being used
 3. Bluetooth adapter info
 4. The list of currently paired Bluetooth devices

Which can be accomplished using commands as follows:

=== The BlueZ version ===

{{{
$ bluetoothctl --version
 1. List the exact manufacturers, and model numbers of all devices involved.
 1. Which Bluetooth version do all involved devices support
 1. The bluez version of your Ubuntu based device: {{{
bluetoothctl --version
Line 46: Line 28:

=== The kernel version ===

{{{
$ uname -a
 1. Bluetooth adapter information: {{{
hciconfig -a
Line 52: Line 31:

===
Bluetooth adapter info ===

{{{
$ hciconfig -a
}}}

===
List of paired devices ===

{{{
$ bluetoothctl
 1. List of paired devices: {{{
bluetoothctl
Line 67: Line 37:
 1. Post the results of the following terminal command: {{{
rfkill list
}}}
 1. Necessary bluetooth log files in debug mode as per below
Line 68: Line 42:
= Capturing logs for Bluetooth debugging = == Capturing bluetooth logs files in debug mode ==
Line 70: Line 44:
This section will cover the details of capturing the necessary log files to ease debugging of the Bluetooth related issues. It is divided into several sections and at the end of it you will know which log files are important, how to enable more verbose logging for Bluetooth and PulseAudio as well as how to sniff the HCI (https://en.wikipedia.org/wiki/List_of_Bluetooth_protocols#HCI) communication between the Bluetooth stack and the Bluetooth chip.

==
What are the important log files and what can be found in them ==


“The necessary log files” phrase basically boils down to the set of system logs. These are as follows
:
This section will cover the details of capturing the necessary log files to ease debugging of the Bluetooth related issues. It is divided into several sections and at the end of it you will know which log files are important, how to enable more verbose logging for Bluetooth and PulseAudio as well as how to sniff the [[https://en.wikipedia.org/wiki/List_of_Bluetooth_protocols#HCI|HCI]] communication between the Bluetooth stack and the Bluetooth chip. Which log file depends on the device one is using:
Line 80: Line 48:
Line 86: Line 53:
Line 94: Line 60:
||syslog||The bluetoothd, pulseaudio and ofono daemons output their verbose logging to syslog when enabled. It is the source of the state of the Bluetooth stack and other involved components used to understand what has happened on the Bluetooth stack level.|| ||syslog||The bluetooth daemon (bluetoothd), pulseaudio and ofono daemons output their verbose logging to syslog when enabled. It is the source of the state of the Bluetooth stack and other involved components used to understand what has happened on the Bluetooth stack level.||
Line 103: Line 69:
Line 106: Line 71:
The table below describes their role in detail The table below describes their role in detail:
Line 109: Line 74:
||bluetoothd||This is the Bluetooth daemon (i.e. the stack). It provides the core operations (search for devices, pair, etc..) and Bluetooth profiles such as A2DP (music streaming), HID (human interface devices), etc and exposes a DBus API for the applications to talk to it.||
||pulseaudio||PulseAudio is the sound server and the bluetoothd uses it to correctly route the audio streams so that the music finds its way to the Bluetooth-connected headset rather than through the speakers (unless selected explicitly to do so). In general every Bluetooth-connected headset appears to PulseAudio as an independent sound card and is managed by it as any other sound card.||
||bluetoothd||This is the Bluetooth daemon (i.e. the stack). It provides the core operations (search for devices, pair, etc.) and Bluetooth profiles such as A2DP (music streaming), HID (human interface devices), etc. and exposes a DBus API for the applications to talk to it.||
||pulseaudio||PulseAudio is the sound server and bluetoothd uses it to correctly route the audio streams so that the music finds its way to the Bluetooth-connected headset rather than through the speakers (unless selected explicitly to do so). In general every Bluetooth-connected headset appears to PulseAudio as an independent sound card and is managed by it as any other sound card.||
Line 117: Line 82:
The steps are as follows:

1. Enable verbose logging for bluetoothd
2. Enable verbose logging for pulseaudio

Enable verbose logging for bluetoothd.

{{{
$ sudo sed -i 's/bluetoothd/bluetoothd \-d/g' /etc/init/bluetooth.conf
 1. Enable verbose logging for bluetoothd: {{{
sudo sed -i 's/bluetoothd/bluetoothd \-d/g' /etc/init/bluetooth.conf
Line 127: Line 85:

Enable verbose logging for pulseaudio.

{{{
$ sudo sed -i 's/pulseaudio/pulseaudio \-d/g' /usr/lib/systemd/user/pulseaudio.service
 1. Enable verbose logging for pulseaudio: {{{
sudo sed -i 's/pulseaudio/pulseaudio \-d/g' /usr/lib/systemd/user/pulseaudio.service
Line 136: Line 91:
The steps are as follows:

 1. Log in to the device using adb (must enable developer mode in the settings) or ssh
 2. Mount the system partition read / write (it is read only by default)
 3. Enable verbose logging for bluetoothd
 4. Enable verbose logging for pulseaudio
 5. Enable verbose logging for ofonod

==== Log in to the device: ====
 1. Log in to the device using adb (must enable developer mode in the settings) or ssh:
Line 149: Line 95:

====
Mount the system partition read / write: ====
 1. Mount the system partition read / write (it is read only by default):
Line 153: Line 97:
phablet@ubuntu-phablet:~$ sudo mount -o remount,rw / sudo mount -o remount,rw /
Line 155: Line 99:

==== Enable verbose logging for bluetoothd. ====

It can be done in two ways. First for an already running daemon by sending SIGUSR2 to it. Second by adding the ‘-d’ switch to its exec line.


If /etc/init/bluetooth.override exists do the following:
 1. Enabling verbose logging for bluetoothd can be done in two ways. First for an already running daemon by sending SIGUSR2 to it. Second by adding the ‘-d’ switch to its exec line. If /etc/init/bluetooth.override exists do the following: {{{
sudo sed -i 's/exec \/usr\/sbin\/bluetoothd \-c \/etc\/bluetooth\/touch.conf/exec \/usr\/sbin\/bluetoothd \-c \/etc\/bluetooth\/touch.conf -d/g' /etc/init/bluetooth.override
}}}
Otherwise: {{{
sudo sed -i 's/exec \/usr\/sbin\/bluetoothd/exec \/usr\/sbin\/bluetoothd -d/g' /etc/init/bluetooth.conf
}}}
 1. Enable verbose logging for pulseaudio:
Line 164: Line 107:
phablet@ubuntu-phablet:~$ sudo sed -i 's/exec \/usr\/sbin\/bluetoothd \-c \/etc\/bluetooth\/touch.conf/exec \/usr\/sbin\/bluetoothd \-c \/etc\/bluetooth\/touch.conf -d/g' /etc/init/bluetooth.override sudo sed -i 's/--start/--start --log-level=debug/g' /usr/share/upstart/sessions/pulseaudio.conf
Line 166: Line 109:

otherwise:
 1. Enable verbose logging for ofonod:
Line 170: Line 111:
phablet@ubuntu-phablet:~$ sudo sed -i 's/exec \/usr\/sbin\/bluetoothd/exec \/usr\/sbin\/bluetoothd -d/g' /etc/init/bluetooth.conf
}}}

==== Enable verbose logging for pulseaudio: ====

{{{
phablet@ubuntu-phablet:~$ sudo sed -i 's/--start/--start --log-level=debug/g' /usr/share/upstart/sessions/pulseaudio.conf
}}}

==== Enable verbose logging for ofonod: ====

{{{
phablet@ubuntu-phablet:~$ sudo sed -i 's/exec ofonod/exec ofonod \-d/g' /etc/init/bluetooth.override
sudo sed -i 's/exec ofonod/exec ofonod \-d/g' /etc/init/bluetooth.override
Line 187: Line 116:
The above steps are automated by the bt-device-enable.sh script available here: https://github.com/bergotorino/bt-debugging-tools The above steps are automated by the bt-device-enable.sh script available [[https://github.com/bergotorino/bt-debugging-tools|here]].  
Line 189: Line 118:
== How to use btmon to capture an HCI trace == === How to use btmon to capture an HCI trace ===
Line 191: Line 120:
The HCI trace is a snapshot of the communication between the Bluetooth host (which means software stack) and the Bluetooth controller (which means the chip). The ‘btmon’ tool can be used to capture such for both live debugging and saving it for later. The HCI trace is a snapshot of the communication between the Bluetooth host (software stack) and the Bluetooth controller (the chip). The ‘btmon’ tool can be used to capture such for both live debugging and saving it for later. Note that the HCI trace needs to be captured at the same time the Bluetooth issue occurs.
Line 196: Line 125:
Line 198: Line 126:
$ sudo btmon sudo btmon
Line 202: Line 130:
Line 204: Line 131:
$ sudo btmon --write ~/hcitrace.snoop sudo btmon --write ~/hcitrace.snoop
Line 208: Line 135:
Line 210: Line 136:
$ sudo btmon --write ~/hcitrace.snoop | tee ~/hcitrace.txt sudo btmon --write ~/hcitrace.snoop | tee ~/hcitrace.txt
Line 215: Line 141:
Note that the HCI trace is only useful for debugging a Bluetooth issue if it has been captured at the same time the issue occurred.

== Summary ==
=== Script for automatic log collection ===
Line 221: Line 145:
== Working with log files == = Working with log files =
Line 225: Line 149:
=== syslog === == syslog ==
Line 238: Line 162:
$ grep ‘bluetoothd\|pulseaudio\|ofonod’ ./syslog > syslog-light grep ‘bluetoothd\|pulseaudio\|ofonod’ ./syslog > syslog-light
Line 241: Line 165:
=== snoop files === == snoop files ==

Debugging Central

This page is part of the debugging series — pages with debugging details for a variety of Ubuntu packages.

WARNING

If you're going to attach the log files mentioned below, be warned that they might include private information like phone numbers. If you're asked to share such log files, please redact any information you don't feel comfortable sharing and post the results to your bug report.

Reporting the bug on Launchpad

Ubuntu bluetooth bugs are tracked on Launchpad. When filing a report, please ensure one is using apport. For more on this, please see here.

The package to use with apport can be:

  • bluez - Issues in the bluetooth protcol stack

  • linux - Hardware dependent issues

  • Issues could be caused by the desktop environment (GNOME, KDE, etc.), or its Bluetooth applications.
  • If any doubts, feel free to file it under bluez and it will be rerouted as applicable.

Once one has reported the bug to Launchpad, it is vital to include the required information that will allow developers to address your issue.

Information required to include in a bug report

  1. List the exact manufacturers, and model numbers of all devices involved.
  2. Which Bluetooth version do all involved devices support
  3. The bluez version of your Ubuntu based device:

    bluetoothctl --version
  4. Bluetooth adapter information:

    hciconfig -a
  5. List of paired devices:

    bluetoothctl
    [bluetooth]# show
    [bluetooth]# devices
    [bluetooth]# info <mac addr of any device you have problems with>
  6. Post the results of the following terminal command:

    rfkill list
  7. Necessary bluetooth log files in debug mode as per below

Capturing bluetooth logs files in debug mode

This section will cover the details of capturing the necessary log files to ease debugging of the Bluetooth related issues. It is divided into several sections and at the end of it you will know which log files are important, how to enable more verbose logging for Bluetooth and PulseAudio as well as how to sniff the HCI communication between the Bluetooth stack and the Bluetooth chip. Which log file depends on the device one is using:

On desktop:

  • /var/log/syslog

On Ubuntu Touch based devices:

  • /var/log/syslog
  • /home/phablet/.cache/upstart/application-legacy-ubuntu-system-settings.log
  • /home/phablet/.cache/upstart/dbus.log

Additionally:

  • HCI trace captured with btmon

The table below summarizes what information these files carry:

Log file

What it contains

syslog

The bluetooth daemon (bluetoothd), pulseaudio and ofono daemons output their verbose logging to syslog when enabled. It is the source of the state of the Bluetooth stack and other involved components used to understand what has happened on the Bluetooth stack level.

ubuntu-system-settings-log

The Ubuntu System Settings on the Ubuntu Touch devices (phone, tablet) logs here. It is useful for knowing what is happening on the level above the Bluetooth stack itself.

dbus.log

DBus is the IPC communication layer between the Ubuntu System Settings and the Bluetooth stack. DBus saves its debug information to this log file which can be useful to tell if both of the parties are able to communicate.

HCI trace

In general the term “HCI trace” refers to the sniffed communication between the Bluetooth host (which means the software stack) and the Bluetooth controller (which means the chip). It contains the full communication between these two and thus can be used to retrace the exact chain of commands / events. In many cases, it is extremely helpful. However, reading and understanding the trace requires Bluetooth knowledge.

Generating log files with debugging information

Under the normal circumstances the system log files just include warning and errors. This is a design decision to not pollute the system with big log files as the “debug logs” are very verbose.

In general, switching on the debugging information is as easy as adding the ‘-d’ switch to the exec line of the daemon for which this mode should be enabled. For Bluetooth there are, in general, three system components (thus daemons) to consider: bluetoothd, pulseaudio and ofonod.

The table below describes their role in detail:

daemon

role

bluetoothd

This is the Bluetooth daemon (i.e. the stack). It provides the core operations (search for devices, pair, etc.) and Bluetooth profiles such as A2DP (music streaming), HID (human interface devices), etc. and exposes a DBus API for the applications to talk to it.

pulseaudio

PulseAudio is the sound server and bluetoothd uses it to correctly route the audio streams so that the music finds its way to the Bluetooth-connected headset rather than through the speakers (unless selected explicitly to do so). In general every Bluetooth-connected headset appears to PulseAudio as an independent sound card and is managed by it as any other sound card.

ofonod

oFono is responsible for the mobile telephony part andbluetoothd uses it to place and answer phone calls. It is not, however, involved in call audio (the HFP audio) at all as this is usually routed, for efficiency, through PCM and completely bypasses the Bluetooth software stack.

Note that it is only required to enable debugging logs for bluetoothd and enabling it for the rest of these components depends on the issue that is to be debugged. For example the issues with pairing will not require any of them, the problems with music playback will require pulseaudio and problems with telephony will require ofonod and pulseaudio. The rule of thumb is that when you are unsure, enable more than less.

On Ubuntu Desktop

  1. Enable verbose logging for bluetoothd:

    sudo sed -i 's/bluetoothd/bluetoothd \-d/g' /etc/init/bluetooth.conf
  2. Enable verbose logging for pulseaudio:

    sudo sed -i 's/pulseaudio/pulseaudio \-d/g' /usr/lib/systemd/user/pulseaudio.service

On Ubuntu Touch based device (phone or tablet)

  1. Log in to the device using adb (must enable developer mode in the settings) or ssh:

$ adb shell
  1. Mount the system partition read / write (it is read only by default):

sudo mount -o remount,rw /
  1. Enabling verbose logging for bluetoothd can be done in two ways. First for an already running daemon by sending SIGUSR2 to it. Second by adding the ‘-d’ switch to its exec line. If /etc/init/bluetooth.override exists do the following:

    sudo sed -i 's/exec \/usr\/sbin\/bluetoothd \-c \/etc\/bluetooth\/touch.conf/exec \/usr\/sbin\/bluetoothd \-c \/etc\/bluetooth\/touch.conf -d/g' /etc/init/bluetooth.override

Otherwise:

sudo sed -i 's/exec \/usr\/sbin\/bluetoothd/exec \/usr\/sbin\/bluetoothd -d/g' /etc/init/bluetooth.conf
  1. Enable verbose logging for pulseaudio:

sudo sed -i 's/--start/--start --log-level=debug/g' /usr/share/upstart/sessions/pulseaudio.conf
  1. Enable verbose logging for ofonod:

sudo sed -i 's/exec ofonod/exec ofonod \-d/g' /etc/init/bluetooth.override

Enable the Ubuntu Touch device automagically

The above steps are automated by the bt-device-enable.sh script available here.

How to use btmon to capture an HCI trace

The HCI trace is a snapshot of the communication between the Bluetooth host (software stack) and the Bluetooth controller (the chip). The ‘btmon’ tool can be used to capture such for both live debugging and saving it for later. Note that the HCI trace needs to be captured at the same time the Bluetooth issue occurs.

The ‘btmon’ executed without any parameters will offer live debugging which will print in a ‘tail -f’ fashion an ongoing exchange of the commands and events between the stack and the chip. It is possible however to make it save the data in the snoop format (https://tools.ietf.org/html/rfc1761) which can later be viewed using for example Wireshark (https://www.wireshark.org).

Live debugging:

sudo btmon

Saving it for later:

sudo btmon --write ~/hcitrace.snoop

Additionally, someone who would like to have a text version available for later too would execute it in a following way:

sudo btmon --write ~/hcitrace.snoop | tee ~/hcitrace.txt

The nice thing about btmon and how it works is that it is possible to have several versions of it executed simultaneously. This allows capturing logs as in the last example in one shell and viewing the live in another.

Script for automatic log collection

The bt-collect-logs.sh script available here: https://github.com/bergotorino/bt-debugging-tools can automatically fetch, pack and pull the logs from the device.

Working with log files

In this section you will read a few tips on how to make reading logs for Bluetooth debugging more productive.

syslog

The first thing to look at is the syslog and while it is a great source of knowledge it contains a lot of noise and usually happens to be long. I try to reboot my device (or check the output from the date command) before I start to capture logs and I do it to have a ‘marker’ in the syslog that I know of. This gives me the possibility to remove everything that has happened before with a single delete and focus only on the following lines.

It is also better to open the syslog file not in gedit because it happens to stall a bit when loading large files. Something like vim is preferable for that along with enabling syntax highlighting for syslog files.

:set filetype syslog

The last thing to do might be to remove the lines other than coming from bluetoothd, pulseaudio and ofonod so that there is less noise and there is no need for much scrolling.

grep ‘bluetoothd\|pulseaudio\|ofonod’ ./syslog > syslog-light

snoop files

Wireshark can open the snoop files and with its powerful abilities to filter out and colorize packets, it is a handy tool. Someone who knows a bit about Bluetooth might benefit a lot just by reading those logs.

DebuggingBluetooth (last edited 2017-05-08 06:53:59 by kzapalowicz)