hci link tx timeout with BCM43438

* hci link tx timeout with BCM43438
@ 2021-09-13  4:32 Takahashi Hideki 2 (郄橋 英樹)
  2021-11-28 23:59 ` Takahashi Hideki 2 (郄橋 英樹)
  0 siblings, 1 reply; 2+ messages in thread
From: Takahashi Hideki 2 (郄橋 英樹) @ 2021-09-13  4:32 UTC (permalink / raw)
  To: linux-bluetooth

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

^ permalink raw reply	[flat|nested] 2+ messages in thread