Bug 200155

Summary: rtl8723bu bluetooth logs "hciX: last event is not cmd complete" during scan
Product: Drivers Reporter: Diego (diego.ml)
Component: BluetoothAssignee: linux-bluetooth (linux-bluetooth)
Status: NEW ---    
Severity: normal    
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 4.16.x Subsystem:
Regression: No Bisected commit-id:

Description Diego 2018-06-21 08:46:37 UTC
This problems is always reproducible. This is related to:
https://bugzilla.kernel.org/show_bug.cgi?id=198699
but I want to report the problem for a specific chip and a specific situation.

In particular when the rtl8723bu Bluetooth chip is used and I start a scan from bluetoothctl I always get the following log message at regular intervals (every 16 seconds):
[  242.417297] Bluetooth: hci0: last event is not cmd complete (0x0f)
[  258.417303] Bluetooth: hci0: last event is not cmd complete (0x0f)
[  274.418306] Bluetooth: hci0: last event is not cmd complete (0x0f)
[  290.417300] Bluetooth: hci0: last event is not cmd complete (0x0f)

Devices tested:
Edimax EW-7611ULB
https://www.edimax.com/edimax/merchandise/merchandise_detail/data/edimax/global/wireless_adapters_n150/ew-7611ulb/
$ lsusb -d 7392:a611
Bus 001 Device 048: ID 7392:a611 Edimax Technology Co., Ltd

LW Technologies LM817:
https://www.lm-technologies.com/product/wifi-and-bluetooth-smart-ready-4-0-usb-dual-mode-adapter-lm817/
# lsusb -d 0bda:b720
Bus 004 Device 004: ID 0bda:b720 Realtek Semiconductor Corp.

Example kernel log when attaching Edimax device:
[Jun20 11:44] usb 1-1.1: new high-speed USB device number 49 using xhci_hcd
[  +0.138607] usb 1-1.1: New USB device found, idVendor=7392, idProduct=a611
[  +0.000008] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  +0.000005] usb 1-1.1: Product: Edimax Wi-Fi N150 Bluetooth4.0 USB Adapter
[  +0.000004] usb 1-1.1: Manufacturer: Realtek
[  +0.000004] usb 1-1.1: SerialNumber: 00e04c000001
[  +0.129966] Bluetooth: hci1: rtl: examining hci_ver=06 hci_rev=000b lmp_ver=06 lmp_subver=8723
[  +0.000004] Bluetooth: hci1: rtl: loading rtl_bt/rtl8723b_config.bin
[  +0.000174] bluetooth hci1: Direct firmware load for rtl_bt/rtl8723b_config.bin failed with error -2
[  +0.000004] Bluetooth: hci1: rtl: loading rtl_bt/rtl8723b_fw.bin
[  +0.000802] Bluetooth: hci1: rom_version status=0 version=1
[  +0.000010] Bluetooth: hci1: cfg_sz 0, total size 22496


How to reproduce the problem
$ bluetoothctl 
Agent registered
[bluetooth]# list
Controller 74:DA:38:E6:58:F3 localhost.localdomain #2 [default]
[...]
[bluetooth]# show
Controller 74:DA:38:E6:58:F3 (public)
        Name: localhost.localdomain #2
        Alias: localhost.localdomain #2
        Class: 0x000c010c
        Powered: yes
        Discoverable: no
        Pairable: yes
        UUID: Audio Source              (0000110a-0000-1000-8000-00805f9b34fb)
        UUID: Audio Sink                (0000110b-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control        (0000110e-0000-1000-8000-00805f9b34fb)
        UUID: PnP Information           (00001200-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
        UUID: Generic Access Profile    (00001800-0000-1000-8000-00805f9b34fb)
        UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
        Modalias: usb:v1D6Bp0246d0532
        Discovering: no
[bluetooth]# scan on
Discovery started
[CHG] Controller 74:DA:38:E6:58:F3 Discovering: yes
[NEW] Device C5:CE:A1:9E:E0:42 C5-CE-A1-9E-E0-42

The error log will start as the user gives the "scan on" command and will stop with the "scan off" command.
Comment 1 Diego 2018-06-22 14:17:42 UTC
I should mention that the error message doesn't prevent scan, connection or other features that I'm aware of to work properly.