Bug 206457

Summary:	Gamepad Dualshock4 CUH-ZCT2U doesn't pair or connect
Product:	Drivers	Reporter:	arael78
Component:	Bluetooth	Assignee:	linux-bluetooth (linux-bluetooth)
Status:	NEW ---
Severity:	blocking	CC:	digitalmarkethubs, kai.heng.feng, neotouch.cci
Priority:	P1
Hardware:	Intel
OS:	Linux
Kernel Version:	5.5+	Subsystem:
Regression:	Yes	Bisected commit-id:

Description arael78 2020-02-07 13:35:12 UTC

Pairing the Dualshock4 controller does not complete correctly, even after several attempts.

Once the pairing is apparently completed (I have to switch off the controller to interrupt the pairing process), when I try to connect it it doesn't stay connected.

I have checked the dmesg and apparently there is a buffer overflow.

I can pair a bluetooth headset to my laptop and the Dualshock4 pairs with my samsung tablet without problems but when I try to pair the dualshock4 to the laptop, running kernel 5.5 and current 5.5+ it doesn't work. I tried other kernels from 5.0 up. None worked.

Dmesg output:

[ 4.099796] Bluetooth: Core ver 2.22
[ 4.099833] Bluetooth: HCI device and connection manager initialized
[ 4.099837] Bluetooth: HCI socket layer initialized
[ 4.099839] Bluetooth: L2CAP socket layer initialized
[ 4.099842] Bluetooth: SCO socket layer initialized
[ 4.128978] Bluetooth: hci0: Firmware revision 0.0 build 10 week 41 2018
[ 6.855412] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 6.855413] Bluetooth: BNEP filters: protocol multicast
[ 6.855416] Bluetooth: BNEP socket layer initialized
[ 14.234706] Bluetooth: RFCOMM TTY layer initialized
[ 14.234711] Bluetooth: RFCOMM socket layer initialized
[ 14.234715] Bluetooth: RFCOMM ver 1.11
[ 117.427931] Bluetooth: Dropping L2CAP data: receive buffer overflow

If I try to use USB cable I get this error:

[ 1882.762621] usb 1-1: new full-speed USB device number 6 using xhci_hcd
[ 1882.913951] usb 1-1: New USB device found, idVendor=054c, idProduct=09cc, bcdDevice= 1.00
[ 1882.913956] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 1882.913960] usb 1-1: Product: Wireless Controller
[ 1882.913962] usb 1-1: Manufacturer: Sony Interactive Entertainment
[ 1882.951627] usbcore: registered new interface driver snd-usb-audio
[ 1882.952799] sony 0003:054C:09CC.0004: failed to retrieve feature report 0x81 with the DualShock 4 MAC address
[ 1882.952943] sony 0003:054C:09CC.0004: hidraw1: USB HID v81.11 Gamepad [Sony Interactive Entertainment Wireless Controller] on usb-0000:00:14.0-1/input3
[ 1882.952945] sony 0003:054C:09CC.0004: failed to claim input
[ 1883.072399] retire_capture_urb: 28 callbacks suppressed

My distro is Ubuntu 19.04 and I have already filed a bug there. I was asked to submit a report here too. On that report there are other logs which might be useful here. Let me know if it is enough or if you need more info.

https://bugs.launchpad.net/ubuntu/+source/bluez/+bug/1861063

Thank you very much for your help.

Comment 3 arael78 2020-07-10 10:35:17 UTC

Same issue happens with the kernel 5.6.10. Is there anything else I can do to provide more information?

Comment 4 arael78 2020-08-04 23:15:53 UTC

I have tried the kernel 5.8.0 and the controller cannot connect.

The previous error messages are gone. But the result is the same, the light on the controller is blinking but no successful pairing.

Comment 5 arael78 2020-08-04 23:31:50 UTC

Here is the log from running bluetoothd with options -n an -d:

The dualshock device is D0_27_96_19_12_33.

bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr D0:27:96:19:12:33, rssi -51 flags 0x0000 eir_len 42
bluetoothd[9774]: src/device.c:device_create() dst D0:27:96:19:12:33
bluetoothd[9774]: src/device.c:device_new() address D0:27:96:19:12:33
bluetoothd[9774]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_D0_27_96_19_12_33
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -51
bluetoothd[9774]: src/device.c:device_set_class() /org/bluez/hci0/dev_D0_27_96_19_12_33 0x002508
bluetoothd[9774]: src/device.c:btd_device_set_temporary() temporary 0
bluetoothd[9774]: src/agent.c:agent_ref() 0x5579ce015af0: ref=2
bluetoothd[9774]: src/device.c:bonding_request_new() Requesting bonding for D0:27:96:19:12:33
bluetoothd[9774]: src/agent.c:agent_ref() 0x5579ce015af0: ref=3
bluetoothd[9774]: src/agent.c:agent_unref() 0x5579ce015af0: ref=2
bluetoothd[9774]: src/adapter.c:suspend_discovery() 
bluetoothd[9774]: src/adapter.c:adapter_bonding_attempt() hci0 bdaddr D0:27:96:19:12:33 type 0 io_cap 0x01
bluetoothd[9774]: src/adapter.c:add_whitelist_complete() D0:27:96:19:12:33 added to kernel whitelist
bluetoothd[9774]: src/adapter.c:suspend_discovery_complete() status 0x00
bluetoothd[9774]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0 method 1
bluetoothd[9774]: src/adapter.c:connected_callback() hci0 device D0:27:96:19:12:33 connected eir_len 26
bluetoothd[9774]: src/adapter.c:new_link_key_callback() hci0 new key for D0:27:96:19:12:33 type 4 pin_len 0 store_hint 1
bluetoothd[9774]: src/device.c:device_set_bonded() 
bluetoothd[9774]: src/device.c:device_bonding_complete() bonding 0x5579ce036410 status 0x00
bluetoothd[9774]: src/device.c:device_bonding_complete() Proceeding with service discovery
bluetoothd[9774]: src/agent.c:agent_unref() 0x5579ce015af0: ref=1
bluetoothd[9774]: src/adapter.c:resume_discovery() 
bluetoothd[9774]: src/adapter.c:trigger_start_discovery() 
bluetoothd[9774]: src/adapter.c:cancel_passive_scanning() 
bluetoothd[9774]: src/adapter.c:pair_device_complete() Success (0x00)
bluetoothd[9774]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr D0:27:96:19:12:33 type 0 status 0x0
bluetoothd[9774]: src/device.c:device_bonding_complete() bonding (nil) status 0x00
bluetoothd[9774]: src/adapter.c:resume_discovery() 
bluetoothd[9774]: src/adapter.c:trigger_start_discovery() 
bluetoothd[9774]: src/adapter.c:cancel_passive_scanning() 
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() 
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() adapter->current_discovery_filter == 1
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() sending MGMT_OP_START_SERVICE_DISCOVERY 127, 7, 0
bluetoothd[9774]: src/adapter.c:start_discovery_complete() status 0x00
bluetoothd[9774]: src/adapter.c:discovering_callback() hci0 type 7 discovering 1 method 1
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -92 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -92 delta 0
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -92 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -92 delta 0
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0 method 1
bluetoothd[9774]: src/adapter.c:trigger_start_discovery() 
bluetoothd[9774]: src/adapter.c:cancel_passive_scanning() 
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() 
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() adapter->current_discovery_filter == 1
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() sending MGMT_OP_START_SERVICE_DISCOVERY 127, 7, 0
bluetoothd[9774]: src/adapter.c:start_discovery_complete() status 0x00
bluetoothd[9774]: src/adapter.c:discovering_callback() hci0 type 7 discovering 1 method 1
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -92 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -92 delta 0
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0 method 1
bluetoothd[9774]: src/adapter.c:trigger_start_discovery() 
bluetoothd[9774]: src/adapter.c:cancel_passive_scanning() 
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() 
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() adapter->current_discovery_filter == 1
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() sending MGMT_OP_START_SERVICE_DISCOVERY 127, 7, 0
bluetoothd[9774]: src/adapter.c:start_discovery_complete() status 0x00
bluetoothd[9774]: src/adapter.c:discovering_callback() hci0 type 7 discovering 1 method 1
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -92 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -92 delta 0
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -93 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -93 delta 1
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -92 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -92 delta 1
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0 method 1
bluetoothd[9774]: src/adapter.c:trigger_start_discovery() 
bluetoothd[9774]: src/adapter.c:cancel_passive_scanning() 
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() 
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() adapter->current_discovery_filter == 1
bluetoothd[9774]: src/adapter.c:start_discovery_timeout() sending MGMT_OP_START_SERVICE_DISCOVERY 127, 7, 0
bluetoothd[9774]: src/adapter.c:start_discovery_complete() status 0x00
bluetoothd[9774]: src/adapter.c:discovering_callback() hci0 type 7 discovering 1 method 1
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -93 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -93 delta 1
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -91 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -91 delta 2
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: D0:27:96:19:12:33: error updating services: Connection timed out (110)
bluetoothd[9774]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_D0_27_96_19_12_33 err -110
bluetoothd[9774]: src/adapter.c:dev_disconnected() Device D0:27:96:19:12:33 disconnected, reason 2
bluetoothd[9774]: src/adapter.c:adapter_remove_connection() 
bluetoothd[9774]: plugins/policy.c:disconnect_cb() reason 2
bluetoothd[9774]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr D0:27:96:19:12:33 type 0 status 0xe
bluetoothd[9774]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
bluetoothd[9774]: src/device.c:device_bonding_failed() status 14
bluetoothd[9774]: src/adapter.c:resume_discovery() 
bluetoothd[9774]: src/adapter.c:trigger_start_discovery() 
bluetoothd[9774]: src/adapter.c:cancel_passive_scanning() 
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -92 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -92 delta 1
bluetoothd[9774]: src/device.c:device_set_flags() flags 0
bluetoothd[9774]: src/adapter.c:device_found_callback() hci0 addr 02:11:8D:DA:78:CB, rssi -92 flags 0x0004 eir_len 31
bluetoothd[9774]: src/device.c:device_set_legacy() legacy 0
bluetoothd[9774]: src/device.c:device_set_rssi_with_delta() rssi -92 delta 0
bluetoothd[9774]: src/device.c:device_set_flags() flags 0