Music audio is not transferred to headset after it is connected

[Konrad Zapałowicz]

Device and Ubuntu version
=====================

Tested on Krillin [Aquaris E4.5], with BlueZ 5.37

phablet@ubuntu-phablet:~$ lsb_release -rd
Description: Ubuntu 15.04
Release: 15.04
phablet@ubuntu-phablet:~$

Tested with:
1. Sony SBH52 headset
2. Philips SHB5500 headphones

Description:
=========

In disconnect state play the music on the phone and do the connection (bluetoothctl connect <device>).

Audio is not transferred to the BT headset but it still plays on the phone instead. On the other hand the bluetoothctl and UI shows that the device is connected. The headset blinkenlights indicate that it is connected too.

The audio is properly routed again after the incoming call is made and rejected/accepted+terminated.

[Simon Fels (morphis)]

Can you add required debug information by following https://wiki.ubuntu.com/DebuggingBluetooth ?

[Konrad Zapałowicz (kzapalowicz)]

phablet@ubuntu-phablet:~$ hciconfig -a
hci0: Type: BR/EDR Bus: UART
        BD Address: 4C:74:03:5F:10:BE ACL MTU: 1021:4 SCO MTU: 184:1
        UP RUNNING PSCAN
        RX bytes:73786 acl:706 sco:0 events:6532 errors:0
        TX bytes:3446513 acl:6213 sco:0 commands:437 errors:0
        Features: 0xbf 0x3e 0x8d 0xfe 0xdb 0xff 0x5b 0x87
        Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3
        Link policy: RSWITCH SNIFF
        Link mode: SLAVE ACCEPT
        Name: 'Aquaris E4.5 Ubuntu Edition'
        Class: 0x5c020c
        Service Classes: Rendering, Capturing, Object Transfer, Telephony
        Device Class: Phone, Smart phone
        HCI Version: 4.0 (0x6) Revision: 0x0
        LMP Version: 4.0 (0x6) Subversion: 0x0
        Manufacturer: MediaTek, Inc. (70)

phablet@ubuntu-phablet:~$ bluetoothctl
[NEW] Controller 4C:74:03:5F:10:BE Aquaris E4.5 Ubuntu Edition [default]
[NEW] Device 68:76:4F:6C:31:E9 SBH52
[bluetooth]# show
Controller 4C:74:03:5F:10:BE
        Name: Aquaris E4.5 Ubuntu Edition
        Alias: Aquaris E4.5 Ubuntu Edition
        Class: 0x5c020c
        Powered: yes
        Discoverable: no
        Pairable: yes
        UUID: Headset AG (00001112-0000-1000-8000-00805f9b34fb)
        UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control (0000110e-0000-1000-8000-00805f9b34fb)
        UUID: Generic Access Profile (00001800-0000-1000-8000-00805f9b34fb)
        UUID: PnP Information (00001200-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
        UUID: Audio Source (0000110a-0000-1000-8000-00805f9b34fb)
        UUID: Audio Sink (0000110b-0000-1000-8000-00805f9b34fb)
        UUID: Handsfree Audio Gateway (0000111f-0000-1000-8000-00805f9b34fb)
        UUID: Message Notification Se.. (00001133-0000-1000-8000-00805f9b34fb)
        UUID: Phonebook Access Server (0000112f-0000-1000-8000-00805f9b34fb)
        Modalias: usb:v1D6Bp0246d0525
        Discovering: no
[bluetooth]# devices
Device 68:76:4F:6C:31:E9 SBH52
[bluetooth]# info 68:76:4F:6C:31:E9
Device 68:76:4F:6C:31:E9
        Name: SBH52
        Alias: SBH52
        Class: 0x240404
        Icon: audio-card
        Paired: yes
        Trusted: yes
        Blocked: no
        Connected: yes
        LegacyPairing: yes
        UUID: Audio Sink (0000110b-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control (0000110e-0000-1000-8000-00805f9b34fb)
        UUID: Handsfree (0000111e-0000-1000-8000-00805f9b34fb)

Now the music is playing through headset, let's disconnect:

[bluetooth]# disconnect 68:76:4F:6C:31:E9
Attempting to disconnect from 68:76:4F:6C:31:E9
Successful disconnected
[CHG] Device 68:76:4F:6C:31:E9 Connected: no
[bluetooth]# connect 68:76:4F:6C:31:E9
Attempting to connect to 68:76:4F:6C:31:E9
[CHG] Device 68:76:4F:6C:31:E9 Connected: yes
Connection successful
[CHG] Device 68:76:4F:6C:31:E9 UUIDs: 0000110b-0000-1000-8000-00805f9b34fb
[CHG] Device 68:76:4F:6...

[Konrad Zapałowicz (kzapalowicz)]

If there is an incoming call between disconnecting the accessory and connecting it back again the music plays just fine over the BT.

connect accessory
play music (goes through BT)
disconnect accessory
incoming call (reject or accept/terminate)
connect accessory
play music (goes through BT)

in other case it is bad

connect accessory
play music (goes through BT)
disconnect accessory
connect accessory
play music (*not* through BT)

[Konrad Zapałowicz (kzapalowicz)]

There are two differences in the logs.

First:

In case there is no call in between of disconnection and connection after the connection is made the 'card' is created with the profile set to 'off'. This is later reset to profile a2dp_sink.

[pulseaudio] backend-ofono.c: New HF card found: /card_2
[pulseaudio] module-bluez5-device.c: Using a2dp_sink profile as default
[pulseaudio] card.c: Created 2 "bluez_card.68_76_4F_6C_31_E9"
[pulseaudio] module-bluez5-device.c: Default profile not connected, selecting off profile
[pulseaudio] module-bluez5-device.c: Created card (current profile off)
(...)
[pulseaudio] module-bluez5-device.c: Setting default profile a2dp_sink
[pulseaudio] module-bluez5-device.c: Setting new profile a2dp_sink for card (current off)
[pulseaudio] module-bluez5-device.c: Initializing profile a2dp_sink

In case there is a call in between the card is created with a2dp_sink profile.

Second:

without an incoming call in between of disconnection and connection there is no such line in the logs:

[pulseaudio] sink-input.c: Successfully moved sink input 0 to bluez_sink.68_76_4F_6C_31_E9.

[Konrad Zapałowicz (kzapalowicz)]

The information from debugging pulseaudio:

0. Info

phablet@ubuntu-phablet:~$ pactl info
Server String: /run/user/32011/pulse/native
Library Protocol Version: 30
Server Protocol Version: 30
Is Local: yes
Client Index: 26
Tile Size: 65496
User Name: phablet
Host Name: ubuntu-phablet
Server Name: pulseaudio
Server Version: 6.0
Default Sample Specification: s16le 2ch 44100Hz
Default Channel Map: front-left,front-right
Default Sink: bluez_sink.68_76_4F_6C_31_E9
Default Source: source.primary
Cookie: babf:0d7f

1.

Sinks:

phablet@ubuntu-phablet:~$ pactl list sinks

This is the state after the headset is connected from the 2nd time. Notice that the music is playing through Sink#0 although it should go through BT headset.

Sink #0
        State: RUNNING
        Name: sink.primary
        Description: Droid sink primary
        Driver: module-droid-card.c

Sink #1
        State: SUSPENDED
        Name: sink.fake.sco
        Description: Null Output
        Driver: module-null-sink.c

Sink #3
        State: SUSPENDED
        Name: bluez_sink.68_76_4F_6C_31_E9
        Description: SBH52
        Driver: module-bluez5-device.c

2.

Headset as a card:

Card #2
        Name: bluez_card.68_76_4F_6C_31_E9
        Driver: module-bluez5-device.c
        Owner Module: 24
        Properties:
                device.description = "SBH52"
                device.string = "68:76:4F:6C:31:E9"
                device.api = "bluez"
                device.class = "sound"
                device.bus = "bluetooth"
                device.form_factor = "headset"
                bluez.path = "/org/bluez/hci0/dev_68_76_4F_6C_31_E9"
                bluez.class = "0x240404"
                bluez.alias = "SBH52"
                device.icon_name = "audio-headset-bluetooth"
                device.intended_roles = "phone"
        Profiles:
                a2dp_sink: High Fidelity Playback (A2DP Sink) (sinks: 1, sources: 0, priority: 10, available: yes)
                headset_head_unit: Headset Head Unit (HSP/HFP) (sinks: 1, sources: 1, priority: 20, available: yes)
                off: Off (sinks: 0, sources: 0, priority: 0, available: yes)
        Active Profile: a2dp_sink
        Ports:
                headset-output: Headset (priority: 0, latency offset: 0 usec)
                        Part of profile(s): a2dp_sink, headset_head_unit
                headset-input: Headset (priority: 0, latency offset: 0 usec)
                        Part of profile(s): headset_head_unit

3.

This test goes through BT headset:

phablet@ubuntu-phablet:~$ paplay /usr/share/sounds/alsa/Front_Left.wav

[Pat McGowan (pat-mcgowan)]

MX4 on proposed 266
Rockfish RF-MA82 headset (no mic) is paired

Notification for SMS plays in headset
Incoming call ringtone played in speakers
Voice call in speakers
When the call is ended. I notice the BT volume control pops up again, but the indicator shows the BT control during the call

[Konrad Zapałowicz (kzapalowicz)]

The further test have concluded that the line

1. [pulseaudio] sink-input.c: Successfully moved sink input 0 to bluez_sink.68_76_4F_6C_31_E9.

is missing because module-switch-on-connect skips switching for default sink

2. [pulseaudio] module-switch-on-connect.c: koza: not switching to internal device, returning...
3. [pulseaudio] module-switch-on-connect.c: koza: not switching to default sink, returning...

and when that happens the line that produces the 1st optput is never called.

[Konrad Zapałowicz (kzapalowicz)]

The attachment contains the logs: syslog and pulseaudio state (where arrows); captured for the following test case:

## Test Case:

 connect BT
-->
 play
 disconnect BT
-->
 play
 connect BT
-->
 play
 disconnect BT
 incoming call
-->
 connect BT
-->
 play
 disconnect BT