espressif/esp-hosted

esp-hosted-ng: HCI controller may dead while sending data via BT RFCOMM

Opened this issue · 34 comments

MrSumi commented

Hi guys, we got problem while using BT RFCOMM server in esp-hosted-ng:

  • RFCOMM connection broken after transfering some data.
  • The next RFCOMM connection can't setup after last connection broken, until reset hci.

Environment:

ESP driver: ESP32 SDIO(WiFi) + UART(BT)
Linux Host: kernel 5.15.71, bluez 5.65
Commit: 651abba

Steps to reproduce:

  1. Linux host attach the ESP32 btattach -B /dev/ttymxc0 -S 921600 -P h4 &, and set hci up hciconfig hci0 up.
  2. Linux host setup RFCOMM server rfcomm watch /dev/rfcomm0 3 &.
  3. Connect the RFCOMM server and transfer data, the connection would broken about 20min (not certainly).
  4. Try reconnect the RFCOMM server and failed, it could connect but not setting up RFCOMM.
  5. Linux host reset the hci controller hciconfig hci0 reset.
  6. Try reconnect the RFCOMM server and success.

Here's logs in ESP32 serial port:
Serial Debug 2024-4-23 11328.txt

Here's logs in Linux btmon when connect and broken:
btmon_connect_and_broken3.log

Here's logs in Linux btmon when reconnect failed:
btmon_could_not_connect3.log

There're no errors arise in Linux dmesg, we are not sure if there might some problem in the ESP32 HCI controller?

mantriyogesh commented

@MrSumi ,

The logs you attached contain some garbage characters, which makes hard to understand the debug log.
Could you please re-attach the log?

Also, please confirm if you are reloading the kernel driver while hciattach is still running and then only this issue is observed?

MrSumi commented

@MrSumi ,

The logs you attached contain some garbage characters, which makes hard to understand the debug log. Could you please re-attach the log?

Also, please confirm if you are reloading the kernel driver while hciattach is still running and then only this issue is observed?

The btmon logs could be opened with Wireshark.

And, i didn't reload the kernel driver (.ko), i reset the hci controller with hciconfig. I think it just affect the HCI controller part in ESP32, and the btattach and the kernel driver is still running.

MrSumi commented

Any progress？

MrSumi commented

Further more, i had tried latest commit(920c418) on master, but it still happens.
This time, i caught a dump log on ESP32: esp32_dump_log.txt

Looking forward to your reply.

mantriyogesh commented

Hello @MrSumi ,

Sorry for the delay, we are trying to reproduce this problem at our setup.
We will get back to you asap on this.

mantriyogesh commented

@kapilkedawat, any progress ahead on this?

mantriyogesh commented

@MrSumi ,

The issue is with Bluetooth internal team. We are awaiting the update from them right now.

mantriyogesh commented

@MrSumi ,
Fix released by the Bluetooth team, we will integrate and test and let you notify further.

MrSumi commented

@MrSumi , Fix released by the Bluetooth team, we will integrate and test and let you notify further.

Thanks for your exciting news, we are awaiting your fix commit.

mantriyogesh commented

This issue related to espressif/esp-idf#13656, Fixed in IDF master: espressif/esp-idf@88774ee

NG needs a rebase of IDF to commit after this to take this change.

MrSumi commented

This issue related to espressif/esp-idf#13656, Fixed in IDF master: espressif/esp-idf@88774ee

NG needs a rebase of IDF to commit after this to take this change.

I didn't find any NG commit rebase on espressif/esp-idf@88774ee
Have you already push the rebased commit, or i should rebase the IDF by myselft?

kapilkedawat commented

@Shreyas0-7 please help to update IDF version based on release branch commit.

Shreyas0-7 commented

Hey @MrSumi Please find the below patch
0001-fix-esp_hosted_ng-fix-bt-error-rebase-5.1.zip
Please use git am --binary patch_name to apply the patch
As this fix is not in a stable tag yet, we will officially update IDF version when we have a stable tag

MrSumi commented

Hey @MrSumi Please find the below patch 0001-fix-esp_hosted_ng-fix-bt-error-rebase-5.1.zip Please use git am --binary patch_name to apply the patch As this fix is not in a stable tag yet, we will officially update IDF version when we have a stable tag

Thanks a lot!
I would try this patch, and take further testing.

MrSumi commented

Hey @MrSumi Please find the below patch 0001-fix-esp_hosted_ng-fix-bt-error-rebase-5.1.zip Please use git am --binary patch_name to apply the patch As this fix is not in a stable tag yet, we will officially update IDF version when we have a stable tag

Thanks a lot!
I would try this patch, and take further testing.

MrSumi commented

Hi @Shreyas0-7 , i try applying your patch, but it causes link errors:

.espressif/tools/xtensa-esp32-elf/esp-12.2.0_20230208/xtensa-esp32-elf/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld: esp-idf/main/libmain.a(cmd.c.obj):(.literal.sta_connection+0xc): undefined reference to esp_wifi_connect_internal' .espressif/tools/xtensa-esp32-elf/esp-12.2.0_20230208/xtensa-esp32-elf/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld: esp-idf/main/libmain.a(cmd.c.obj):(.literal.process_auth_request+0x34): undefined reference to esp_wifi_issue_auth_internal'
.espressif/tools/xtensa-esp32-elf/esp-12.2.0_20230208/xtensa-esp32-elf/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld: esp-idf/main/libmain.a(cmd.c.obj):(.literal.process_assoc_request+0x4): undefined reference to esp_wifi_issue_assoc_internal' .espressif/tools/xtensa-esp32-elf/esp-12.2.0_20230208/xtensa-esp32-elf/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld: esp-idf/main/libmain.a(cmd.c.obj): in function sta_connection':
esp-hosted/esp_hosted_ng/esp/esp_driver/network_adapter/main/cmd.c:133: undefined reference to esp_wifi_connect_internal' .espressif/tools/xtensa-esp32-elf/esp-12.2.0_20230208/xtensa-esp32-elf/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld: esp-idf/main/libmain.a(cmd.c.obj): in function process_auth_request':
esp-hosted/esp_hosted_ng/esp/esp_driver/network_adapter/main/cmd.c:1193: undefined reference to esp_wifi_issue_auth_internal' .espressif/tools/xtensa-esp32-elf/esp-12.2.0_20230208/xtensa-esp32-elf/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld: esp-idf/main/libmain.a(cmd.c.obj): in function process_assoc_request':
esp-hosted/esp_hosted_ng/esp/esp_driver/network_adapter/main/cmd.c:1308: undefined reference to `esp_wifi_issue_assoc_internal'
collect2: error: ld returned 1 exit status
make[2]: *** [CMakeFiles/network_adapter.elf.dir/build.make:479: network_adapter.elf] Error 1
make[1]: *** [CMakeFiles/Makefile2:1963: CMakeFiles/network_adapter.elf.dir/all] Error 2
make: *** [Makefile:136: all] Error 2

May i ask whitch commit did your patch base on?

Shreyas0-7 commented

Hey @MrSumi it's based on master, you will have to run cmake . or setup.sh in esp_driver directory in order to copy relevant libraries to esp-idf submodule. Please make sure you have committed all local changes you have made before running this script.

MrSumi commented

Hi guys, i tried rebase IDF to espressif/esp-idf@88774ee, but it still crash.
Here's the crash log from ESP32 serial: ESP32_dump.txt

Shreyas0-7 commented

Hey @MrSumi I checked your logs and I think patch is not applied correctly can you please check this again

  • move to esp_driver folder and rm -rf esp-idf
  • move to parent directory esp_hosted apply the patch provided using git am --binary patch_name
  • and then run cmake . or setup.sh in esp_driver folder.
MrSumi commented

Hi @Shreyas0-7 I followed your steps to apply patch.
This time, ESP32 didn't crash, but just no response with hci command.

Here's the log from ESP32 serial:
ESP32_dump_20240614.txt

Here's the command line from Linux host:

[root@superx5a:~]# hciconfig -a
hci0: Type: Primary Bus: SDIO
BD Address: E4:65:B8:23:AE:56 ACL MTU: 1021:9 SCO MTU: 255:4
DOWN INIT RUNNING
RX bytes:-1790678496 acl:127446 sco:0 events:941144 errors:0
TX bytes:77463975 acl:0 sco:0 commands:0 errors:0
Features: 0xbf 0xee 0xcd 0xfe 0xdb 0xff 0x7b 0x87
Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV3
Link policy: RSWITCH SNIFF
Link mode: PERIPHERAL ACCEPT

[root@superx5a:~]# hciconfig hci0 reset
Can't init device hci0: Connection timed out (110)

MrSumi commented

Hi guys，any progress with this issue?

MrSumi commented

Hi guys，any progress with this issue?

mantriyogesh commented

@Shreyas0-7 Can you please check?

Shreyas0-7 commented

Hey @MrSumi can you please do a throughput test to check if the connection is fine.
Here is the link for the steps Raw throughput

MrSumi commented

Hey @Shreyas0-7, I'm pretty sure that the SDIO connection works fine at first.
But my host module was builded with NO TP.
I've tried rebuilding the host module with TP, but it failed with errors below.

./esp-hosted/esp_hosted_ng/host/esp_stats.c: In function ‘raw_tp_tx_process’:
./esp-hosted/esp_hosted_ng/host/esp_stats.c:60:10: error: implicit declaration of function ‘kthread_should_stop’; did you mean ‘thread_saved_sp’? [-Werror=implicit-function-declaration]
while (!kthread_should_stop()) {
^~~~~~~~~~~~~~~~~~~
thread_saved_sp
./esp-hosted/esp_hosted_ng/host/esp_stats.c: In function ‘process_raw_tp_flags’:
./esp-hosted/esp_hosted_ng/host/esp_stats.c:113:23: error: implicit declaration of function ‘kthread_run’; did you mean ‘it_real_fn’? [-Werror=implicit-function-declaration]
raw_tp_tx_thread = kthread_run(raw_tp_tx_process, NULL, "raw tp thrd");
^~~~~~~~~~~
it_real_fn
./esp-hosted/esp_hosted_ng/host/esp_stats.c:113:21: warning: assignment makes pointer from integer without a cast [-Wint-conversion]
raw_tp_tx_thread = kthread_run(raw_tp_tx_process, NULL, "raw tp thrd");
^
./esp-hosted/esp_hosted_ng/host/esp_stats.c: In function ‘test_raw_tp_cleanup’:
./esp-hosted/esp_hosted_ng/host/esp_stats.c:162:9: error: implicit declaration of function ‘kthread_stop’; did you mean ‘ether_setup’? [-Werror=implicit-function-declaration]
ret = kthread_stop(raw_tp_tx_thread);
^~~~~~~~~~~~
ether_setup
cc1: some warnings being treated as errors
make[2]: *** [scripts/Makefile.build:304: ./esp-hosted/esp_hosted_ng/host/esp_stats.o] Error 1
make[1]: *** [Makefile:1525: module./esp-hosted/esp_hosted_ng/host] Error 2

Shreyas0-7 commented

@MrSumi Can you please try including #include <linux/kthread.h> in esp_stats.c

MrSumi commented

@Shreyas0-7 Thanks for helping.
I builded and ran the TP test, it seems that the SDIO connection works fine at first, but broken after i setup bluetooth connection.
Here're some logs from dmesg:

……
[69071.638176] esp32_sdio: log_raw_tp_stats_timer_cb: 1129-1130 sec 34777 kbits/sec
[69072.662168] esp32_sdio: log_raw_tp_stats_timer_cb: 1130-1131 sec 34697 kbits/sec
[69073.686183] esp32_sdio: log_raw_tp_stats_timer_cb: 1131-1132 sec 34914 kbits/sec
[69074.710180] esp32_sdio: log_raw_tp_stats_timer_cb: 1132-1133 sec 35142 kbits/sec
[69075.734191] esp32_sdio: log_raw_tp_stats_timer_cb: 1133-1134 sec 34526 kbits/sec
[69076.758173] esp32_sdio: log_raw_tp_stats_timer_cb: 1134-1135 sec 34891 kbits/sec
[69077.782172] esp32_sdio: log_raw_tp_stats_timer_cb: 1135-1136 sec 34515 kbits/sec
[69078.806189] esp32_sdio: log_raw_tp_stats_timer_cb: 1136-1137 sec 34606 kbits/sec
[69079.830173] esp32_sdio: log_raw_tp_stats_timer_cb: 1137-1138 sec 35188 kbits/sec
[69080.854189] esp32_sdio: log_raw_tp_stats_timer_cb: 1138-1139 sec 34230 kbits/sec
[69081.878183] esp32_sdio: log_raw_tp_stats_timer_cb: 1139-1140 sec 34367 kbits/sec
[69082.902170] esp32_sdio: log_raw_tp_stats_timer_cb: 1140-1141 sec 34173 kbits/sec
[69083.926179] esp32_sdio: log_raw_tp_stats_timer_cb: 1141-1142 sec 34846 kbits/sec
[69084.950172] esp32_sdio: log_raw_tp_stats_timer_cb: 1142-1143 sec 34697 kbits/sec
[69085.974180] esp32_sdio: log_raw_tp_stats_timer_cb: 1143-1144 sec 35245 kbits/sec
[69086.998185] esp32_sdio: log_raw_tp_stats_timer_cb: 1144-1145 sec 33100 kbits/sec
[69088.022177] esp32_sdio: log_raw_tp_stats_timer_cb: 1145-1146 sec 32097 kbits/sec
[69089.046181] esp32_sdio: log_raw_tp_stats_timer_cb: 1146-1147 sec 32701 kbits/sec
[69090.070176] esp32_sdio: log_raw_tp_stats_timer_cb: 1147-1148 sec 25401 kbits/sec
[69091.094190] esp32_sdio: log_raw_tp_stats_timer_cb: 1148-1149 sec 0 kbits/sec
[69091.926187] Bluetooth: hci0: command 0x0c14 tx timeout
[69092.118175] esp32_sdio: log_raw_tp_stats_timer_cb: 1149-1150 sec 0 kbits/sec
[69093.142172] esp32_sdio: log_raw_tp_stats_timer_cb: 1150-1151 sec 0 kbits/sec
[69093.974199] Bluetooth: hci0: command 0x2008 tx timeout
[69094.166169] esp32_sdio: log_raw_tp_stats_timer_cb: 1151-1152 sec 0 kbits/sec
[69095.190187] esp32_sdio: log_raw_tp_stats_timer_cb: 1152-1153 sec 0 kbits/sec
[69095.990210] Bluetooth: hci0: command 0x2009 tx timeout
[69096.214182] esp32_sdio: log_raw_tp_stats_timer_cb: 1153-1154 sec 0 kbits/sec
[69097.238170] esp32_sdio: log_raw_tp_stats_timer_cb: 1154-1155 sec 0 kbits/sec
[69098.006205] Bluetooth: hci0: command 0x200a tx timeout
[69098.262169] esp32_sdio: log_raw_tp_stats_timer_cb: 1155-1156 sec 0 kbits/sec
[69099.286180] esp32_sdio: log_raw_tp_stats_timer_cb: 1156-1157 sec 0 kbits/sec
[69100.022198] Bluetooth: hci0: command 0x2006 tx timeout
[69100.310187] esp32_sdio: log_raw_tp_stats_timer_cb: 1157-1158 sec 0 kbits/sec
[69101.338177] esp32_sdio: log_raw_tp_stats_timer_cb: 1158-1159 sec 0 kbits/sec
[69102.038195] Bluetooth: hci0: command 0x200a tx timeout
[69102.358190] esp32_sdio: log_raw_tp_stats_timer_cb: 1159-1160 sec 0 kbits/sec
[69103.382179] esp32_sdio: log_raw_tp_stats_timer_cb: 1160-1161 sec 0 kbits/sec
[69104.054187] Bluetooth: hci0: command 0x1405 tx timeout
[69104.406169] esp32_sdio: log_raw_tp_stats_timer_cb: 1161-1162 sec 0 kbits/sec
[69105.430169] esp32_sdio: log_raw_tp_stats_timer_cb: 1162-1163 sec 0 kbits/sec
[69106.070194] Bluetooth: hci0: command 0x0c2d tx timeout
[69106.454182] esp32_sdio: log_raw_tp_stats_timer_cb: 1163-1164 sec 0 kbits/sec
[69107.482174] esp32_sdio: log_raw_tp_stats_timer_cb: 1164-1165 sec 0 kbits/sec
[69108.086193] Bluetooth: hci0: command 0x2008 tx timeout
[69108.502178] esp32_sdio: log_raw_tp_stats_timer_cb: 1165-1166 sec 0 kbits/sec
[69109.526176] esp32_sdio: log_raw_tp_stats_timer_cb: 1166-1167 sec 0 kbits/sec
[69110.106269] Bluetooth: hci0: command 0x2009 tx timeout
[69110.550172] esp32_sdio: log_raw_tp_stats_timer_cb: 1167-1168 sec 0 kbits/sec
[69111.574181] esp32_sdio: log_raw_tp_stats_timer_cb: 1168-1169 sec 0 kbits/sec
[69112.150196] Bluetooth: hci0: command 0x2006 tx timeout
[69112.598178] esp32_sdio: log_raw_tp_stats_timer_cb: 1169-1170 sec 0 kbits/sec
[69113.622170] esp32_sdio: log_raw_tp_stats_timer_cb: 1170-1171 sec 0 kbits/sec
[69114.166196] Bluetooth: hci0: command 0x200a tx timeout
[69114.646180] esp32_sdio: log_raw_tp_stats_timer_cb: 1171-1172 sec 0 kbits/sec
[69115.670181] esp32_sdio: log_raw_tp_stats_timer_cb: 1172-1173 sec 0 kbits/sec
[69116.182219] Bluetooth: hci0: command 0x0c14 tx timeout
[69116.694180] esp32_sdio: log_raw_tp_stats_timer_cb: 1173-1174 sec 0 kbits/sec
[69117.718177] esp32_sdio: log_raw_tp_stats_timer_cb: 1174-1175 sec 0 kbits/sec
[69118.198208] Bluetooth: hci0: command 0x2008 tx timeout
[69118.742169] esp32_sdio: log_raw_tp_stats_timer_cb: 1175-1176 sec 0 kbits/sec
[69119.766172] esp32_sdio: log_raw_tp_stats_timer_cb: 1176-1177 sec 0 kbits/sec
[69120.214210] Bluetooth: hci0: command 0x2009 tx timeout
[69120.790169] esp32_sdio: log_raw_tp_stats_timer_cb: 1177-1178 sec 0 kbits/sec
[69121.814176] esp32_sdio: log_raw_tp_stats_timer_cb: 1178-1179 sec 0 kbits/sec
[69122.230185] Bluetooth: hci0: command 0x2006 tx timeout
[69122.838171] esp32_sdio: log_raw_tp_stats_timer_cb: 1179-1180 sec 0 kbits/sec
[69123.862173] esp32_sdio: log_raw_tp_stats_timer_cb: 1180-1181 sec 0 kbits/sec
[69124.246192] Bluetooth: hci0: command 0x200a tx timeout
[69124.890168] esp32_sdio: log_raw_tp_stats_timer_cb: 1181-1182 sec 0 kbits/sec
[69125.910168] esp32_sdio: log_raw_tp_stats_timer_cb: 1182-1183 sec 0 kbits/sec
[69126.262185] Bluetooth: hci0: command 0x0c14 tx timeout
[69126.934185] esp32_sdio: log_raw_tp_stats_timer_cb: 1183-1184 sec 0 kbits/sec
[69127.958173] esp32_sdio: log_raw_tp_stats_timer_cb: 1184-1185 sec 0 kbits/sec
[69128.310180] Bluetooth: hci0: command 0x2008 tx timeout
[69128.982173] esp32_sdio: log_raw_tp_stats_timer_cb: 1185-1186 sec 0 kbits/sec
[69130.006172] esp32_sdio: log_raw_tp_stats_timer_cb: 1186-1187 sec 0 kbits/sec
[69130.326192] Bluetooth: hci0: command 0x2009 tx timeout
[69131.030179] esp32_sdio: log_raw_tp_stats_timer_cb: 1187-1188 sec 0 kbits/sec
[69132.054183] esp32_sdio: log_raw_tp_stats_timer_cb: 1188-1189 sec 0 kbits/sec
[69132.342199] Bluetooth: hci0: command 0x2006 tx timeout
[69133.078172] esp32_sdio: log_raw_tp_stats_timer_cb: 1189-1190 sec 0 kbits/sec
[69134.102170] esp32_sdio: log_raw_tp_stats_timer_cb: 1190-1191 sec 0 kbits/sec
[69134.358196] Bluetooth: hci0: command 0x200a tx timeout
[69135.126181] esp32_sdio: log_raw_tp_stats_timer_cb: 1191-1192 sec 0 kbits/sec
[69136.150171] esp32_sdio: log_raw_tp_stats_timer_cb: 1192-1193 sec 0 kbits/sec
[69136.374201] Bluetooth: hci0: command 0x2008 tx timeout
[69137.174188] esp32_sdio: log_raw_tp_stats_timer_cb: 1193-1194 sec 0 kbits/sec
[69138.198185] esp32_sdio: log_raw_tp_stats_timer_cb: 1194-1195 sec 0 kbits/sec
[69139.222170] esp32_sdio: log_raw_tp_stats_timer_cb: 1195-1196 sec 0 kbits/sec
[69140.246177] esp32_sdio: log_raw_tp_stats_timer_cb: 1196-1197 sec 0 kbits/sec
[69141.270167] esp32_sdio: log_raw_tp_stats_timer_cb: 1197-1198 sec 0 kbits/sec
[69142.294182] esp32_sdio: log_raw_tp_stats_timer_cb: 1198-1199 sec 0 kbits/sec
[69143.318176] esp32_sdio: log_raw_tp_stats_timer_cb: 1199-1200 sec 0 kbits/sec
[69144.342169] esp32_sdio: log_raw_tp_stats_timer_cb: 1200-1201 sec 0 kbits/sec
[69145.366178] esp32_sdio: log_raw_tp_stats_timer_cb: 1201-1202 sec 0 kbits/sec
[69146.390169] esp32_sdio: log_raw_tp_stats_timer_cb: 1202-1203 sec 0 kbits/sec
[69147.418179] esp32_sdio: log_raw_tp_stats_timer_cb: 1203-1204 sec 0 kbits/sec
[69148.438180] esp32_sdio: log_raw_tp_stats_timer_cb: 1204-1205 sec 0 kbits/sec
[69149.462168] esp32_sdio: log_raw_tp_stats_timer_cb: 1205-1206 sec 0 kbits/sec
……

MrSumi commented

@Shreyas0-7 I also tried running TP test without BT or WiFi connection, but the SDIO connection still broken after 10087 seconds.

Here're part of Linux dmesg logs:

……
[11397.520934] esp32_sdio: log_raw_tp_stats_timer_cb: 9839-9840 sec 35040 kbits/sec
[11398.540931] esp32_sdio: log_raw_tp_stats_timer_cb: 9840-9841 sec 34218 kbits/sec
[11399.568939] esp32_sdio: log_raw_tp_stats_timer_cb: 9841-9842 sec 34686 kbits/sec
[11400.588938] esp32_sdio: log_raw_tp_stats_timer_cb: 9842-9843 sec 34173 kbits/sec
[11401.612933] esp32_sdio: log_raw_tp_stats_timer_cb: 9843-9844 sec 34789 kbits/sec
[11402.636937] esp32_sdio: log_raw_tp_stats_timer_cb: 9844-9845 sec 34481 kbits/sec
[11403.660939] esp32_sdio: log_raw_tp_stats_timer_cb: 9845-9846 sec 34515 kbits/sec
[11404.684945] esp32_sdio: log_raw_tp_stats_timer_cb: 9846-9847 sec 33260 kbits/sec
[11405.708953] esp32_sdio: log_raw_tp_stats_timer_cb: 9847-9848 sec 32690 kbits/sec
[11406.732937] esp32_sdio: log_raw_tp_stats_timer_cb: 9848-9849 sec 33682 kbits/sec
[11407.756938] esp32_sdio: log_raw_tp_stats_timer_cb: 9849-9850 sec 33192 kbits/sec
[11408.780936] esp32_sdio: log_raw_tp_stats_timer_cb: 9850-9851 sec 8908 kbits/sec
[11409.804941] esp32_sdio: log_raw_tp_stats_timer_cb: 9851-9852 sec 0 kbits/sec
[11410.380968] Bluetooth: hci1: command 0x2008 tx timeout
[11410.828938] esp32_sdio: log_raw_tp_stats_timer_cb: 9852-9853 sec 0 kbits/sec
[11411.852933] esp32_sdio: log_raw_tp_stats_timer_cb: 9853-9854 sec 0 kbits/sec
[11412.396985] Bluetooth: hci1: command 0x2009 tx timeout
[11412.876945] esp32_sdio: log_raw_tp_stats_timer_cb: 9854-9855 sec 0 kbits/sec
[11413.900936] esp32_sdio: log_raw_tp_stats_timer_cb: 9855-9856 sec 0 kbits/sec
[11414.412965] Bluetooth: hci1: command 0x200a tx timeout
[11414.924938] esp32_sdio: log_raw_tp_stats_timer_cb: 9856-9857 sec 0 kbits/sec
[11415.952934] esp32_sdio: log_raw_tp_stats_timer_cb: 9857-9858 sec 0 kbits/sec
[11416.428977] Bluetooth: hci1: command 0x2006 tx timeout
[11416.972933] esp32_sdio: log_raw_tp_stats_timer_cb: 9858-9859 sec 0 kbits/sec
[11417.996946] esp32_sdio: log_raw_tp_stats_timer_cb: 9859-9860 sec 0 kbits/sec
[11418.444964] Bluetooth: hci1: command 0x200a tx timeout
[11419.020935] esp32_sdio: log_raw_tp_stats_timer_cb: 9860-9861 sec 0 kbits/sec
[11420.044942] esp32_sdio: log_raw_tp_stats_timer_cb: 9861-9862 sec 0 kbits/sec
[11420.460984] Bluetooth: hci1: command 0x0c14 tx timeout
[11421.068935] esp32_sdio: log_raw_tp_stats_timer_cb: 9862-9863 sec 0 kbits/sec
[11422.096941] esp32_sdio: log_raw_tp_stats_timer_cb: 9863-9864 sec 0 kbits/sec
[11422.477032] Bluetooth: hci1: command 0x2008 tx timeout
[11423.120940] esp32_sdio: log_raw_tp_stats_timer_cb: 9864-9865 sec 0 kbits/sec
[11424.140945] esp32_sdio: log_raw_tp_stats_timer_cb: 9865-9866 sec 0 kbits/sec
[11424.492968] Bluetooth: hci1: command 0x2009 tx timeout
[11425.164939] esp32_sdio: log_raw_tp_stats_timer_cb: 9866-9867 sec 0 kbits/sec
[11426.188933] esp32_sdio: log_raw_tp_stats_timer_cb: 9867-9868 sec 0 kbits/sec
[11426.508976] Bluetooth: hci1: command 0x2006 tx timeout
[11427.212945] esp32_sdio: log_raw_tp_stats_timer_cb: 9868-9869 sec 0 kbits/sec
[11428.236936] esp32_sdio: log_raw_tp_stats_timer_cb: 9869-9870 sec 0 kbits/sec
[11428.524970] Bluetooth: hci1: command 0x200a tx timeout
[11429.260952] esp32_sdio: log_raw_tp_stats_timer_cb: 9870-9871 sec 0 kbits/sec
[11430.284942] esp32_sdio: log_raw_tp_stats_timer_cb: 9871-9872 sec 0 kbits/sec
[11430.540955] Bluetooth: hci1: command 0x2008 tx timeout
[11431.308936] esp32_sdio: log_raw_tp_stats_timer_cb: 9872-9873 sec 0 kbits/sec
[11432.332945] esp32_sdio: log_raw_tp_stats_timer_cb: 9873-9874 sec 0 kbits/sec
……

Here're part of ESP32 logs:

……
I (10065603) stats: 10062-10063 sec 34017.00 kbits/sec
I (10066603) stats: 10063-10064 sec 33775.50 kbits/sec
I (10067603) stats: 10064-10065 sec 33844.50 kbits/sec
I (10068603) stats: 10065-10066 sec 34109.00 kbits/sec
I (10069603) stats: 10066-10067 sec 33752.50 kbits/sec
I (10070603) stats: 10067-10068 sec 33890.50 kbits/sec
I (10071603) stats: 10068-10069 sec 33902.00 kbits/sec
I (10072603) stats: 10069-10070 sec 33879.00 kbits/sec
I (10073603) stats: 10070-10071 sec 33948.00 kbits/sec
I (10074603) stats: 10071-10072 sec 33810.00 kbits/sec
I (10075603) stats: 10072-10073 sec 34040.00 kbits/sec
I (10076603) stats: 10073-10074 sec 34580.50 kbits/sec
I (10077603) stats: 10074-10075 sec 33867.50 kbits/sec
I (10078603) stats: 10075-10076 sec 34569.00 kbits/sec
I (10079603) stats: 10076-10077 sec 34109.00 kbits/sec
I (10080603) stats: 10077-10078 sec 33936.50 kbits/sec
I (10081603) stats: 10078-10079 sec 33787.00 kbits/sec
I (10082603) stats: 10079-10080 sec 34132.00 kbits/sec
I (10083603) stats: 10080-10081 sec 34051.50 kbits/sec
I (10084603) stats: 10081-10082 sec 33867.50 kbits/sec
I (10085603) stats: 10082-10083 sec 32982.00 kbits/sec
I (10086602) stats: 10083-10084 sec 32729.00 kbits/sec
I (10087602) stats: 10084-10085 sec 32464.50 kbits/sec
I (10088603) stats: 10085-10086 sec 32683.00 kbits/sec
I (10089602) stats: 10086-10087 sec 16525.50 kbits/sec
I (10090602) stats: 10087-10088 sec 0.00 kbits/sec
I (10091602) stats: 10088-10089 sec 0.00 kbits/sec
I (10092602) stats: 10089-10090 sec 0.00 kbits/sec
I (10093602) stats: 10090-10091 sec 0.00 kbits/sec
I (10094602) stats: 10091-10092 sec 0.00 kbits/sec
I (10095602) stats: 10092-10093 sec 0.00 kbits/sec
I (10096602) stats: 10093-10094 sec 0.00 kbits/sec
I (10097602) stats: 10094-10095 sec 0.00 kbits/sec
I (10098602) stats: 10095-10096 sec 0.00 kbits/sec
I (10099602) stats: 10096-10097 sec 0.00 kbits/sec
I (10100602) stats: 10097-10098 sec 0.00 kbits/sec
I (10101602) stats: 10098-10099 sec 0.00 kbits/sec
I (10102603) stats: 10099-10100 sec 0.00 kbits/sec
I (10103602) stats: 10100-10101 sec 0.00 kbits/sec
I (10104603) stats: 10101-10102 sec 0.00 kbits/sec
I (10105603) stats: 10102-10103 sec 0.00 kbits/sec
I (10106602) stats: 10103-10104 sec 0.00 kbits/sec
I (10107603) stats: 10104-10105 sec 0.00 kbits/sec
I (10108603) stats: 10105-10106 sec 0.00 kbits/sec
I (10109602) stats: 10106-10107 sec 0.00 kbits/sec
I (10110603) stats: 10107-10108 sec 0.00 kbits/sec
I (10111602) stats: 10108-10109 sec 0.00 kbits/sec
I (10112603) stats: 10109-10110 sec 0.00 kbits/sec
I (10113602) stats: 10110-10111 sec 0.00 kbits/sec
I (10114603) stats: 10111-10112 sec 0.00 kbits/sec
……

kapilkedawat commented

Hi @MrSumi, this shouldn't happen, could you please explain how the connection is done?

Shreyas0-7 commented

Hey @MrSumi thanks for pointing out the issue, this issue was introduced in 1.0.3 and is fixed internally. Repo will be updated with the fix soon. Thank you

MrSumi commented

@Shreyas0-7 Happy to hear that! please let me know when you have fix update.

PS: I also do another TP testing and it came out the same result, but this time i set 'hci0' and 'espsta0' down.
Here're the linux and esp32 logs:
linux_debug_message_20240701_184116.txt
esp32_debug_message_20240701_184203.txt

Shreyas0-7 commented

@MrSumi Hey issue has been resolved can you please check with the latest changes

MrSumi commented

@MrSumi Hey issue has been resolved can you please check with the latest changes

Thanks for your information, i will run futher testing.