Can't pair with a Volvo car kit

Bug #1572577 reported by Michał Sawicz
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
bluez (Ubuntu)
Confirmed
Undecided
Unassigned
ubuntu-system-settings (Ubuntu)
Confirmed
Undecided
Unassigned

Bug Description

For a while now I'm unable to pair with my car kit. It's a reverse-pair procedure, so the car is trying to initiate the pairing, shows the PIN to enter and goes "failed" - with the phone never showing anything.

Syslog shows, possibly relevant:

Apr 20 15:21:40 ubuntu-phablet bluetoothd[891]: src/device.c:new_auth() Requesting agent authentication for 00:1A:77:F6:D5:2B
[...]
Apr 20 15:21:40 ubuntu-phablet bluetoothd[891]: Agent /com/canonical/SettingsBluetoothAgent/adapteragent replied with an error: org.bluez.Error.Rejected, The request was rejected: RequestPinCode
[...]
Apr 20 15:21:40 ubuntu-phablet bluetoothd[891]: src/device.c:device_cancel_authentication() Canceling authentication request for 00:1A:77:F6:D5:2B

Please find logs, as directed by https://wiki.ubuntu.com/DebuggingBluetooth, attached.

ProblemType: Bug
DistroRelease: Ubuntu 15.04
Package: ubuntu-system-settings 0.3+15.04.20160407-0ubuntu1 [origin: LP-PPA-ci-train-ppa-service-stable-phone-overlay]
Uname: Linux 3.4.67 armv7l
ApportVersion: 2.17.2-0ubuntu1.3touch1
Architecture: armhf
Date: Wed Apr 20 15:31:32 2016
InstallationDate: Installed on 2016-04-14 (6 days ago)
InstallationMedia: Ubuntu 15.04 - armhf (20160414-020305)
SourcePackage: ubuntu-system-settings
UpgradeStatus: No upgrade log present (probably fresh install)
---
ApportVersion: 2.17.2-0ubuntu1.3touch1
Architecture: armhf
CurrentDmesg: Error: command ['dmesg'] failed with exit code 1: dmesg: read kernel buffer failed: Operation not permitted
DistroRelease: Ubuntu 15.04
InstallationDate: Installed on 2016-04-14 (6 days ago)
InstallationMedia: Ubuntu 15.04 - armhf (20160414-020305)
Lsusb: Error: [Errno 2] No such file or directory
Package: bluez 5.37-0ubuntu5~overlay1 [origin: LP-PPA-ci-train-ppa-service-stable-phone-overlay]
PackageArchitecture: armhf
ProcKernelCmdLine: console=ttyMT0,921600n1 vmalloc=496M slub_max_order=0 fixrtc lcm=1-hx8389_qhd_dsi_vdo_truly fps=6657 bootprof.pl_t=511 bootprof.lk_t=1724 printk.disable_uart=1 boot_reason=4 datapart=/dev/mmcblk0p7 systempart=/dev/mmcblk0p6 androidboot.serialno=JB011540 � lcm=1-hx8389_qhd_dsi_vdo_truly fps=6657 bootprof.pl_t=511 bootprof.lk_t=1724 printk.disable_uart=1 boot_reason=4 datapart=/dev/mmcblk0p7 systempart=/dev/mmcblk0p6 androidboot.serialno=JB011540 �
ProcModules:

Tags: vivid third-party-packages
UdevLog: Error: [Errno 2] No such file or directory: '/var/log/udev'
Uname: Linux 3.4.67 armv7l
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups: adm cdrom dialout dip plugdev sudo tty video
_MarkForUpload: True
hciconfig:
 hci0: Type: BR/EDR Bus: UART
  BD Address: B8:64:91:48:2B:21 ACL MTU: 1021:4 SCO MTU: 184:1
  UP RUNNING PSCAN
  RX bytes:4361 acl:59 sco:0 events:213 errors:0
  TX bytes:6120 acl:60 sco:0 commands:131 errors:0
modified.conffile..etc.init.bluetooth.conf: [modified]
mtime.conffile..etc.init.bluetooth.conf: 2016-04-20T15:11:43.487387

Revision history for this message
Michał Sawicz (saviq) wrote :
tags: added: apport-collected
description: updated
Revision history for this message
Michał Sawicz (saviq) wrote : Dependencies.txt

apport information

Revision history for this message
Michał Sawicz (saviq) wrote : ProcCpuinfo.txt

apport information

Revision history for this message
Michał Sawicz (saviq) wrote : ProcEnviron.txt

apport information

Revision history for this message
Michał Sawicz (saviq) wrote : ProcInterrupts.txt

apport information

Revision history for this message
Michał Sawicz (saviq) wrote : SystemImageInfo.txt

apport information

Revision history for this message
Michał Sawicz (saviq) wrote : UdevDb.txt

apport information

Revision history for this message
Michał Sawicz (saviq) wrote : rfkill.txt

apport information

Revision history for this message
Michał Sawicz (saviq) wrote : syslog.txt

apport information

Revision history for this message
Konrad Zapałowicz (kzapalowicz) wrote :

Agent is requested however it replies with "Agent /com/canonical/SettingsBluetoothAgent/adapteragent replied with an error: org.bluez.Error.Rejected, The request was rejected: RequestPinCode"

Revision history for this message
Konrad Zapałowicz (kzapalowicz) wrote :

It seems like a Settings bug that has been fixed a while ago and reopened afterwards.

Revision history for this message
Konrad Zapałowicz (kzapalowicz) wrote :

What I have found in the syslog:

15:21:25 here the car is connecting to the phone, the bluez correctly handles the device:

src/adapter.c:connected_callback() hci0 device 00:1A:77:F6:D5:2B connected eir_len 5
src/device.c:device_create() dst 00:1A:77:F6:D5:2B
src/device.c:device_new() address 00:1A:77:F6:D5:2B
src/device.c:device_new() Creating device /org/bluez/hci0/dev_00_1A_77_F6_D5_2B
src/device.c:device_set_class() /org/bluez/hci0/dev_00_1A_77_F6_D5_2B 0x300408

15:21:26 next the car is disconnecting. The reason 3 means Remote Disconnected and status 0xe means Status Disconnected.

src/adapter.c:dev_disconnected() Device 00:1A:77:F6:D5:2B disconnected, reason 3
src/adapter.c:adapter_remove_connection()
src/adapter.c:adapter_remove_connection() Removing temporary device /org/bluez/hci0/dev_00_1A_77_F6_D5_2B
src/device.c:device_remove() Removing device /org/bluez/hci0/dev_00_1A_77_F6_D5_2B
src/device.c:btd_device_unref() Freeing device /org/bluez/hci0/dev_00_1A_77_F6_D5_2B
src/device.c:device_free() 0xb7837780
plugins/policy.c:disconnect_cb() reason 3
src/adapter.c:bonding_attempt_complete() hci0 bdaddr 00:1A:77:F6:D5:2B type 0 status 0xe

15:21:32 8 seconds later we see that the pin code request callback has kicked in

Apr 20 15:21:32 src/adapter.c:pin_code_request_callback() hci0 00:1A:77:F6:D5:2B
Apr 20 15:21:32 src/device.c:device_create() dst 00:1A:77:F6:D5:2B
Apr 20 15:21:32 src/device.c:device_new() address 00:1A:77:F6:D5:2B
Apr 20 15:21:32 src/device.c:device_new() Creating device /org/bluez/hci0/dev_00_1A_77_F6_D5_2B
Apr 20 15:21:32 src/device.c:new_auth() Requesting agent authentication for 00:1A:77:F6:D5:2B
Apr 20 15:21:32 src/agent.c:agent_ref() 0xb782a140: ref=2
The pairing request is send to the registered agent however it is denied:

Agent /com/canonical/SettingsBluetoothAgent/adapteragent replied with an error: org.bluez.Error.Rejected, The request was rejected: RequestPinCode

As a result the bonding obviously fails:

src/adapter.c:btd_adapter_pincode_reply() hci0 addr 00:1A:77:F6:D5:2B pinlen 0
src/agent.c:agent_unref() 0xb782a140: ref=2
src/agent.c:agent_unref() 0xb782a140: ref=1
src/adapter.c:connect_failed_callback() hci0 00:1A:77:F6:D5:2B status 11
plugins/policy.c:conn_fail_cb() status 11
src/adapter.c:bonding_attempt_complete() hci0 bdaddr 00:1A:77:F6:D5:2B type 0 status 0xb
src/device.c:device_bonding_complete() bonding (nil) status 0x0b
src/device.c:device_cancel_authentication() Canceling authentication request for 00:1A:77:F6:D5:2B
src/device.c:device_bonding_failed() status 11
src/adapter.c:resume_discovery()
src/device.c:device_remove() Removing device /org/bluez/hci0/dev_00_1A_77_F6_D5_2B
src/device.c:btd_device_unref() Freeing device /org/bluez/hci0/dev_00_1A_77_F6_D5_2B
src/device.c:device_free() 0xb7837780

15:21:40 8 seconds later the pin request callback is called again and the whole thing repeats with the same result.

Revision history for this message
Konrad Zapałowicz (kzapalowicz) wrote :

There is a high chance that silo 46 contains fix for this bug

Revision history for this message
Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in bluez (Ubuntu):
status: New → Confirmed
Changed in ubuntu-system-settings (Ubuntu):
status: New → Confirmed
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.