Bug 1279953

This bug appears to have been reported against 'rawhide' during the Fedora 24 development cycle.
Changing version to '24'.

More information and reason for this action is here:
https://fedoraproject.org/wiki/Fedora_Program_Management/HouseKeeping/Fedora24#Rawhide_Rebase

I have found a workaround. If you turn on the bluetooth headset and it auto-connects it doesn't work. But if you open the bluetooth preferences in gnome and manually disconnect and reconnect, everything works properly.

I'm thus moving this to bluez.

I am hitting this here too, but the workaround doesn't work for me. ;( 

I am not sure where the problem actually is. I downgraded bluez and it still was happening.

Happy to help debug, this is quite an anoying little bug...

Hi,

Can you edit /usr/lib/systemd/system/bluetooth.service and
add a '-d' to

ExecStart=/usr/libexec/bluetooth/bluetoothd

like

ExecStart=/usr/libexec/bluetooth/bluetoothd -d

save/exit and restart bluetooth with

systemctl daemon-reload
systecmtl restart bluetooth


Then try and auto-connect and watch it fail.

capture and attach the logs

journalctl -S today > /tmp/logs

That should hopefully be a good start.

If it stays connected, then bluetooth found a sound profile to use
and everything is fine from bluetooth's perspective.  We will see
what the logs say.

Cheers,
Don

Created attachment 1243637 [details]
bluez logs during the connection process

Here's an update. I'm currently running on rawhide. The device appears to connect, but doesn't show up as an audio input/output option at all.

No selinux denials are generated. It simply doesn't work.

Created attachment 1243736 [details]
bluetoothd -d logs

Here's my logs from bluetoothd -d

This is my restarting it with -d, then turning on the headset, letting it connect then going into the gnome sound prefs, changing the output to it and trying to play the test sound (with no sound appearing), then turning it off.

I would imagine that the workflow for bluetooth headsets is probably the most common use of bluetooth. I think it would be great if we could define a Fedora QA test for this workflow.

Hi Kevin,

Your logs seem to indicate everything connected fine.  Even the audio plugin accpeted the headphones.  Then after 30 seconds or so, the kernel received an event that your headset disappears on its own.  Either low battery or some other strangeness.  It does not appear to be the laptop?? doing the disconnecting.

Perhaps change the battery or recharge the headphones?

Cheers,
Don

Hi Nathan,

I now have a wireless lab where we can test bluetooth devices.  I will work with folks to see if we can set that up along with bluetooth mice.  You are right, we should be better than this.

Cheers,
Don

No, that was me turning off the headset. ;) It has no power issues. 

Just during that 30 seconds that it was connected and set as the source/sink (with headset profile) it didn't work. No sound came out of it. The test sound did not play, other sound playing/recording things just hang and don't play or record anything. 

Would it be useful to connect it and play something on the other profile, then switch to headset? or is this just indicating that it's all at some other level where the problem is?

Hi Nathan,

I forgot to responsd in the other comment, reviewing your logs seems to indicate everything started off ok, but for some reason the audio plugin just never fired to connect the headphones to pulseaudio.  During the restart of bluetooth the audio plugin connected to the headphones, but the headphones were still in a disconnected state while the daemon continued its connection process.

Could you turn off the headphones, restart bluetooth daemon, wait about 10 seconds for that to complete, then re-enable the headphones and submit those logs to me to see what is going on there?

Cheers,
Don

Hi Kevin,

This could be at a different level.  The logs indicate everything including the audio sink connected and setup properly.  We might have to setup btmon to see if any traffic is happening.  Maybe it is stuck in pulseaudio.

I have also seen strange selinux issues recently.  Does 'setenforce 0' change the behaviour?

Cheers,
Don

(In reply to Don Zickus from comment #13)
> Hi Nathan,
> 
> I forgot to responsd in the other comment, reviewing your logs seems to
> indicate everything started off ok, but for some reason the audio plugin
> just never fired to connect the headphones to pulseaudio.  During the
> restart of bluetooth the audio plugin connected to the headphones, but the
> headphones were still in a disconnected state while the daemon continued its
> connection process.
> 
> Could you turn off the headphones, restart bluetooth daemon, wait about 10
> seconds for that to complete, then re-enable the headphones and submit those
> logs to me to see what is going on there?

No problem. Doing it now.

Regarding a bluetooth headset test, we should probably do something like the following:

1. Pair device.
2. Audio should play over A2DP by default.
3. Use a VOIP app (or maybe bluejeans.com) and make sure A2DP => HSP happens.
4. Stop using VOIP and make sure HSP => A2DP happens.
5. Check media buttons on the headset (play, pause, back, forward).
6. Power cycle the headset. Make sure device auto-connects.
7. Run all the tests again.

Created attachment 1243749 [details]
bluetooth -d logs

13:58:39 - Restart bluetoothd
14:00:16 - Turn on headset
 ... NO AUDIO DEVICE APPEARS IN CONTROL CENTER ...
14:01:21 - Turn off headset

(In reply to Don Zickus from comment #14)
> Hi Kevin,
> 
> This could be at a different level.  The logs indicate everything including
> the audio sink connected and setup properly.  We might have to setup btmon
> to see if any traffic is happening.  Maybe it is stuck in pulseaudio.

Could be yeah. I did try downgrading pulseaudio with no luck, but it could be still something in there. I will attach a pulseaudio -vvv log.
 
> I have also seen strange selinux issues recently.  Does 'setenforce 0'
> change the behaviour?

No change with permissive. ;(

Created attachment 1243751 [details]
pulseaudio-vvvv-log.txt

Here's a pulseaudio log...

pulseaudio log seems reasonable. It gets the SCO fd, negotiates the right format and seems to be sending audio to the device without errors. Next step is probably take a more detailed log and dump the audio packets (if any). 

It could also be a quirk of the headset where it ignores all packets until it gets a magic command on the RFCOMM channel. Does this device work on any other computer/os you have (so we can check the handshake)?

(In reply to Wim Taymans from comment #20)
> pulseaudio log seems reasonable. It gets the SCO fd, negotiates the right
> format and seems to be sending audio to the device without errors. Next step
> is probably take a more detailed log and dump the audio packets (if any). 

ok. How can I do that? 
> 
> It could also be a quirk of the headset where it ignores all packets until
> it gets a magic command on the RFCOMM channel. Does this device work on any
> other computer/os you have (so we can check the handshake)?

Well, this very headset worked fine on this laptop in the past. It may have been early december since it worked, but it did work fine before. I suppose I could try a f25 live media?

ok. After a sunday afternoon of trying tons of things I finally tracked down my problem. 

linux-firmware-20161205-70.git91ddce49.fc26.noarch -> bluetooth headsets fail. 
linux-firmware-20160923-68.git42ad5367.fc26.noarch + cold boot -> bluetooh headsets work again. 

I was tripped up by needing to do the cold boot for a while but I figured it out. 

(with bad/new firmware):
% sudo journalctl -b -1 -l  | grep -i DDC
Feb 12 15:58:12 sheelba.scrye.com kernel: Bluetooth: hci0: Found Intel DDC parameters: intel/ibt-11-5.ddc
Feb 12 15:58:12 sheelba.scrye.com kernel: Bluetooth: hci0: Failed to send Intel_Write_DDC (-22)

(with older/good firmware): 
% sudo journalctl -b -l  | grep -i DDC
Feb 12 16:09:58 sheelba.scrye.com kernel: Bluetooth: hci0: Found Intel DDC parameters: intel/ibt-11-5.ddc
Feb 12 16:09:58 sheelba.scrye.com kernel: Bluetooth: hci0: Applying Intel DDC parameters completed

I'll try and file my issue upstream on kernel.org bugzilla (unless there's some better way to get intels permissions.

(In reply to Kevin Fenzi from comment #22)
> I'll try and file my issue upstream on kernel.org bugzilla (unless there's
> some better way to get intels permissions.

Can you post the link to the upstream bug here?

Turns out it was already fixed upstream in: 
http://git.kernel.org/cgit/linux/kernel/git/firmware/linux-firmware.git/commit/?id=581f24500138f5e410d51ab63b205be9a52f4c77

and jwb already pushed out a new linux-firmware package in fedora with that.

So, some additional debugging turned out that I had two separate problems. One system I had hit the intel bug above. Another was missing the broadcom firmware altogether. Strangely, both resulted in the same symptoms.

Earlier, I had discussed improving the user testing story of bluetooth. I discussed this with Adam Williamson at DevConf and that resulted in this bug:

https://pagure.io/fedora-qa/issue/500

The goal is to get a set of testing and debugging steps for volunteers to test before Fedora releases to make sure we don't hit some obvious bugs. It would be great to get some review on the proposed test cases. Hopefully Don can provide us with a debugging wiki page to go with the tests (as requested in the bug).

I think this will go a long way towards increasing the quality of our BT UX.

This bug appears to have been reported against 'rawhide' during the Fedora 26 development cycle.
Changing version to '26'.

So i think this is a firmware issue in both cases and is now fixed?

(In reply to Nathaniel McCallum from comment #2)
> I have found a workaround. If you turn on the bluetooth headset and it
> auto-connects it doesn't work. But if you open the bluetooth preferences in
> gnome and manually disconnect and reconnect, everything works properly.
> 
> I'm thus moving this to bluez.

I experience comment #2 on FC26 with a Sony MDR-XB950BT. 
If the headset is discovered and automatically connected, the output profile ("Output" tab in Sound settings, "Profile" combo) is pre-selected to "Headset Head Unit (HSP/HFP)". No sound is hearable in the headset though. 
Switching the profile to "High Fidelity Playback (A2DP Sink)" is executed as in UI/Combo but there's still no sound in the headset. Switching to other tabs like "Input" makes the profile return to "Headset Head Unit (HSP/HFP)". Disconnecting the headset manually and re-connecting it helps. Switching to A2DP works and one can finally enjoy sound over the headset.

Things are working for me now in F26 and rawhide. At the least, this bug shouldn't be needinfo on me.