Cannot pair mako with 2014 Subaru Forester

[Scott Sweeny]

Since the bluez5 transition my mako has not been able to pair with the radio in my 2014 Subaru Forester. When the radio is put into pairing mode the phone sees the CAR_M_MEDIA device, but when I click "connect" the radio immediately shows "failed" and no PIN prompt is shown on the phone. Additionally, the entry in system-settings for the car stereo is left in a limbo state with the "forget" button inactive. The only way to remove the entry is to use bluetoothctl from the command line.

Here's what the phone is currently running:
current build number: 252
device name: mako
channel: ubuntu-touch/rc-proposed/bq-aquaris.en
last update: 2016-03-02 00:31:33
version version: 252
version ubuntu: 20160302
version device: 20160112
version custom: 20160201-5-vivid

[Daniel van Vugt (vanvugt)]

Is it intentional that your device name and channel don't match up?

mako = LG/Google Nexus 4
bq-aquaris = BQ Aquaris (krillin)

So if you've installed the wrong Ubuntu image you might have the wrong kernel and wrong bluetooth driver.

[Scott Sweeny (ssweeny)]

It is intentional, as the bq-aquaris channel includes things like the HERE AGPS service.

My BT keyboard, mouse, and headset all work so it's something to do with the HFP changes that came with bluez5 I have to assume, since before the switch I could pair with the car just fine.

[Pat McGowan (pat-mcgowan)]

some hfp fixes just landed today

[Scott Sweeny (ssweeny)]

Unfortunately the latest rc-proposed image does not fix the problem.

[Scott Sweeny (ssweeny)]

I tried to pair today using bluetoothctl but all I got back was

Failed to pair: org.bluez.Error.AuthenticationRejected

and the same "failed" message on the radio display.

[Konrad Zapałowicz (kzapalowicz)]

@ssweeny

Could you retest with newest images and attach syslog. Thanks

[Scott Sweeny (ssweeny)]

Still didn't work for me.

[Konrad Zapałowicz (kzapalowicz)]

14:15:05 here the car infotainment system is discovered during the device discovery process. The bluez correctly handles the device.

src/adapter.c:device_found_callback() hci0 addr 38:C0:96:BC:D1:10, rssi -52 flags 0x0003 eir_len 5
src/device.c:device_create() dst 38:C0:96:BC:D1:10
src/device.c:device_new() address 38:C0:96:BC:D1:10
src/device.c:device_new() Creating device /org/bluez/hci0/dev_38_C0_96_BC_D1_10
src/device.c:device_set_legacy() legacy 1
src/device.c:device_set_rssi_with_delta() rssi -52
src/device.c:device_set_class() /org/bluez/hci0/dev_38_C0_96_BC_D1_10 0x340408

14:15:08 there is a pairing request that gets denied. The status 5 means Status Auth Failed. At the end the bonding is rescheduled for an another attempt.

src/device.c:bonding_request_new() Requesting bonding for 38:C0:96:BC:D1:10
src/agent.c:agent_ref() 0xb7e242c0: ref=3
src/agent.c:agent_unref() 0xb7e242c0: ref=2
src/adapter.c:suspend_discovery()
src/adapter.c:adapter_bonding_attempt() hci0 bdaddr 38:C0:96:BC:D1:10 type 0 io_cap 0x04
src/adapter.c:add_whitelist_complete() 38:C0:96:BC:D1:10 added to kernel whitelist
src/adapter.c:pin_code_request_callback() hci0 38:C0:96:BC:D1:10
plugins/autopair.c:autopair_pincb() device 38:C0:96:BC:D1:10 0x340408
src/adapter.c:btd_adapter_pincode_reply() hci0 addr 38:C0:96:BC:D1:10 pinlen 4
src/adapter.c:connect_failed_callback() hci0 38:C0:96:BC:D1:10 status 5
plugins/policy.c:conn_fail_cb() status 5
src/adapter.c:bonding_attempt_complete() hci0 bdaddr 38:C0:96:BC:D1:10 type 0 status 0x5
src/device.c:device_bonding_attempt_retry() scheduling retry
src/adapter.c:pair_device_complete() Authentication Failed (0x05)
src/adapter.c:bonding_attempt_complete() hci0 bdaddr 38:C0:96:BC:D1:10 type 0 status 0x5

14:15:12 the 2nd pairing attempt is made. Consequently this attempts fails too however this time with Status Rejected code. (status 11 means Status Rejected`). It is important to note that this happens immediately w/o any waiting time in between (timeout).

src/device.c:device_bonding_retry() retrying bonding
src/adapter.c:adapter_bonding_attempt() hci0 bdaddr 38:C0:96:BC:D1:10 type 0 io_cap 0x04
src/adapter.c:connect_failed_callback() hci0 38:C0:96:BC:D1:10 status 11
plugins/policy.c:conn_fail_cb() status 11
src/adapter.c:bonding_attempt_complete() hci0 bdaddr 38:C0:96:BC:D1:10 type 0 status 0xb
src/device.c:device_bonding_complete() bonding 0xb7e24170 status 0x0b
src/device.c:device_bonding_failed() status 11
src/agent.c:agent_unref() 0xb7e242c0: ref=1
src/adapter.c:resume_discovery()
src/adapter.c:pair_device_complete() Rejected (0x0b)
src/adapter.c:bonding_attempt_complete() hci0 bdaddr 38:C0:96:BC:D1:10 type 0 status 0xb
src/device.c:device_bonding_complete() bonding (nil) status 0x0b
src/device.c:device_bonding_failed() status 11

[Konrad Zapałowicz (kzapalowicz)]

The Ubuntu System Settings log contains such a warning:

14:15:08,530 - WARNING - file:///usr/share/ubuntu/settings/system/qml-plugins/bluetooth/DevicePage.qml:156: TypeError: Cannot read property 'paired' of null

This corresponds to the pairing request that has been issued at the same time.

14:15:08 ubuntu-phablet bluetoothd[2278]: src/device.c:bonding_request_new() Requesting bonding for 38:C0:96:BC:D1:10

Which basically means that the user has clicked one of the discovered devices on the devices list. This triggers the pairing request.

The error from the Ubuntu System Settings also means that the selectedDevice property has not been properly updated. This is set based on the device address and the query goes down to the devices model https://bazaar.launchpad.net/~system-settings-touch/ubuntu-system-settings/trunk/view/head:/plugins/bluetooth/devicemodel.cpp#L564. And it can fail only if there is no device of such address on an internal devices list. This list is updated with addDevice() call https://bazaar.launchpad.net/~system-settings-touch/ubuntu-system-settings/trunk/view/head:/plugins/bluetooth/devicemodel.cpp#L497.

[Scott Sweeny (ssweeny)]

Here's the syslog snippet from when I tried pairing using bluetoothctl

[Konrad Zapałowicz (kzapalowicz)]

Could you test with the latest image that contained bluez 4.x and that would be pre OTA 8.5 as bluez 5 has been introduced there. It is also important to flash everything including kernel. This is to narrow down the update that could cause it also proving that this is in fact bluez 5 update responsible.

[Scott Sweeny (ssweeny)]

Sorry it took so long to get to this, but I was finally able to test on my phone with OTA-8. The pairing worked as expected.

[Daniel van Vugt (vanvugt)]

Reduced priority for Ubuntu Touch bugs.

[Daniel van Vugt (vanvugt)]

Ubuntu Touch is no longer supported.