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.
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 c:device_ create( ) dst 00:1A:77:F6:D5:2B c:device_ new() address 00:1A:77:F6:D5:2B c:device_ new() Creating device /org/bluez/ hci0/dev_ 00_1A_77_ F6_D5_2B c:device_ set_class( ) /org/bluez/ hci0/dev_ 00_1A_77_ F6_D5_2B 0x300408
src/device.
src/device.
src/device.
src/device.
15:21:26 next the car is disconnecting. The reason 3 means Remote Disconnected and status 0xe means Status Disconnected.
src/adapter. c:dev_disconnec ted() Device 00:1A:77:F6:D5:2B disconnected, reason 3 c:adapter_ remove_ connection( ) c:adapter_ remove_ connection( ) Removing temporary device /org/bluez/ hci0/dev_ 00_1A_77_ F6_D5_2B c:device_ remove( ) Removing device /org/bluez/ hci0/dev_ 00_1A_77_ F6_D5_2B c:btd_device_ unref() Freeing device /org/bluez/ hci0/dev_ 00_1A_77_ F6_D5_2B c:device_ free() 0xb7837780 policy. c:disconnect_ cb() reason 3 c:bonding_ attempt_ complete( ) hci0 bdaddr 00:1A:77:F6:D5:2B type 0 status 0xe
src/adapter.
src/adapter.
src/device.
src/device.
src/device.
plugins/
src/adapter.
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 c:device_ create( ) dst 00:1A:77:F6:D5:2B c:device_ new() address 00:1A:77:F6:D5:2B c:device_ new() Creating device /org/bluez/ hci0/dev_ 00_1A_77_ F6_D5_2B c:new_auth( ) Requesting agent authentication for 00:1A:77:F6:D5:2B c:agent_ ref() 0xb782a140: ref=2
Apr 20 15:21:32 src/device.
Apr 20 15:21:32 src/device.
Apr 20 15:21:32 src/device.
Apr 20 15:21:32 src/device.
Apr 20 15:21:32 src/agent.
The pairing request is send to the registered agent however it is denied:
Agent /com/canonical/ SettingsBluetoo thAgent/ 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 c:agent_ unref() 0xb782a140: ref=2 c:agent_ unref() 0xb782a140: ref=1 c:connect_ failed_ callback( ) hci0 00:1A:77:F6:D5:2B status 11 policy. c:conn_ fail_cb( ) status 11 c:bonding_ attempt_ complete( ) hci0 bdaddr 00:1A:77:F6:D5:2B type 0 status 0xb c:device_ bonding_ complete( ) bonding (nil) status 0x0b c:device_ cancel_ authentication( ) Canceling authentication request for 00:1A:77:F6:D5:2B c:device_ bonding_ failed( ) status 11 c:resume_ discovery( ) c:device_ remove( ) Removing device /org/bluez/ hci0/dev_ 00_1A_77_ F6_D5_2B c:btd_device_ unref() Freeing device /org/bluez/ hci0/dev_ 00_1A_77_ F6_D5_2B c:device_ free() 0xb7837780
src/agent.
src/agent.
src/adapter.
plugins/
src/adapter.
src/device.
src/device.
src/device.
src/adapter.
src/device.
src/device.
src/device.
15:21:40 8 seconds later the pin request callback is called again and the whole thing repeats with the same result.