RE: hci link tx timeout with BCM43438

["Takahashi Hideki 2 (郄橋 英樹)" <hideki.takahashi2@jp.ricoh.com>]

Hello All,

Updating the kernel version(4.19.57→5.10.63) fixed the problem.
It seems that bluetooth.ko and hci_uart.ko have fixes. 
Are you fixing them to solve the problem?

[Execution environment]
・Raspberry pi 3 model b
・Raspbian Buster 10 Linux raspberrypi 5.10.63-v7+
・BlueZ 5.58
・Broadcom BCM43438


Thank you for your help.
Best regards,
Hideki Takahashi

-----Original Message-----
From: Takahashi Hideki 2 (郄橋 英樹) <hideki.takahashi2@jp.ricoh.com> 
Sent: Monday, September 13, 2021 1:33 PM
To: linux-bluetooth@vger.kernel.org
Subject: hci link tx timeout with BCM43438

Hello All,

I am developing a system that communicates with BLE on Raspberry Pi.
When the developed system is operated, HCI link down occurs several times a week and BLE communication is disconnected.
Shows the results of syslog and hcidump when communication is interrupted.
From the result of hcidump, I think that it is a problem of hci because communication is not interrupted, but what kind of cause can be considered?
Would you please suggest a solution?

Thank you for your help.
Best regards,
Hideki Takahashi

[Execution environment]
・Raspberry pi 3 model b
・Raspbian Buster 10 Linux raspberrypi 4.19.57-v7+
・BlueZ 5.58
・Broadcom BCM43438

[syslog]
Jun  1 14:59:31 raspberrypi kernel: [2678208.088754] Bluetooth: hci0: link tx timeout Jun  1 14:59:31 raspberrypi kernel: [2678208.088765] Bluetooth: hci0: killing stalled connection xx:xx:xx:xx:xx:xx Jun  1 14:59:31 raspberrypi bluetoothd[901]: src/adapter.c:dev_disconnected() Device xx:xx:xx:xx:xx:xx disconnected, reason 2 Jun  1 14:59:31 raspberrypi bluetoothd[901]: src/adapter.c:adapter_remove_connection()
Jun  1 14:59:31 raspberrypi bluetoothd[901]: plugins/policy.c:disconnect_cb() reason 2 Jun  1 14:59:31 raspberrypi bluetoothd[901]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr xx:xx:xx:xx:xx:xx type 1 status 0xe Jun  1 14:59:31 raspberrypi bluetoothd[901]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e Jun  1 14:59:31 raspberrypi bluetoothd[901]: src/device.c:device_bonding_failed() status 14 Jun  1 14:59:31 raspberrypi bluetoothd[901]: src/adapter.c:resume_discovery() Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/agent.c:add_default_agent() Default agent set to :1.108 /org/bluez/agent Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:set_mode() sending set mode command for index 0 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/agent.c:agent_ref() 0x568110: ref=1 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/agent.c:register_agent() agent :1.108 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:new_settings_callback() Settings: 0x00000ad1 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:settings_changed() Changed settings: 0x00000010 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:settings_changed() Pending settings: 0x00000000 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/device.c:device_remove() Removing device /org/bluez/hci0/dev_xx_xx_xx_xx_xx_xx
Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/device.c:btd_device_unref() Freeing device /org/bluez/hci0/dev_xx_xx_xx_xx_xx_xx
Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/device.c:device_free() 0x56bfb8 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/agent.c:agent_disconnect() Agent :1.108 disconnected Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/agent.c:remove_default_agent() Default agent cleared Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:set_mode() sending set mode command for index 0 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/agent.c:agent_destroy() agent :1.108 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/agent.c:agent_unref() 0x568110: ref=0 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:new_settings_callback() Settings: 0x00000ac1 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:settings_changed() Changed settings: 0x00000010 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:settings_changed() Pending settings: 0x00000000 Jun  1 14:59:34 raspberrypi bluetoothd[901]: src/adapter.c:discovering_callback() hci0 type 6 discovering 1 method 0

[hcidump]
2021-06-01 14:59:31.304383 > ACL data: handle 64 flags 0x02 dlen 27
    ATT: Handle notify (0x1b)
      handle 0x0012
2021-06-01 14:59:31.304682 < HCI Command: Disconnect (0x01|0x0006) plen 3
    handle 64 reason 0x13
    Reason: Remote User Terminated Connection
2021-06-01 14:59:31.305089 > HCI Event: Command Status (0x0f) plen 4
    Disconnect (0x01|0x0006) status 0x00 ncmd 1
2021-06-01 14:59:31.345332 > HCI Event: Disconn Complete (0x05) plen 4
    status 0x00 handle 64 reason 0x16
    Reason: Connection Terminated by Local Host
2021-06-01 14:59:34.992038 < HCI Command: LE Set Random Address (0x08|0x0005) plen 6
    bdaddr 37:68:FE:C8:77:51
2021-06-01 14:59:34.992509 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Random Address (0x08|0x0005) ncmd 1
    status 0x00