Bluetooth Issue with 88W8997 Chipset

[virti_choksi]

Dear NXP Team,

I am currently working with an 88W8997 chipset, and my DUT setup details are outlined below:

• Wi-Fi Driver: SD-WLAN-SD-BT-8997-U16-MMC-W16.68.10.p162-16.26.10.p162-C4X16693_V4-MGPL
• Processor: BG5CT
• OS: Android 12
• Linux version: 4.9.178

Description: Our objective is to conduct a stress test on the Bluetooth functionality. We initiated a cycle of enabling and disabling Bluetooth 150 times with a 3-minute interval of sleep between each enable and disable action through the script. However, after approximately 90 or 100 cycles, a Bluetooth crash was observed. Moreover, during the startup, our device's default Bluetooth state is configured to be ON, but after the crash occurs and we reboot the device, manual reactivation of Bluetooth is required.

To assist you in identifying the potential cause or any missing steps, I've attached the logcat log for your reference.

Your insights and guidance on this matter would be immensely appreciated. If there are any specific details or logs you require to better understand the situation, please do let me know, and I'll promptly provide them.

Thank you for your time and assistance in advance.

Best regards,
Virti Choksi

[ocourson]

Dear @virti_choksi 

We have reproduces the issue locally, and found a fix.

We will send you a test firmware which includes the fix by private message.

Please provide feedback on the test firmware and share HCI + SDIO driver logs if it fails.

Please note that this test PVT FW is only for test purposes for this issue and it shouldn't be used for any other verification or test purpose. It could fail for any other scenarios or test cases except this issue case.

We have validated this firmware locally and it is working fine, so please check on your side and provide feedback.

Regards,

Olivier

[Christine_Li]

Hi, virti,

I have sent the PVT test firmware to your email.

please check whether it works on your side and let me know.

best wishes,

Christine.

[virti_choksi]

Hello @Christine_Li,

I've received the PVT test firmware and conducted thorough testing on our end.

The test results are positive—the firmware is working well, and we haven't encountered any issues during our evaluation.

Thank you for your support.

Best Regards, 

Virti Choksi

[Christine_Li]

Hi, @virti_choksi 

Can you please help to confirm with the customer, whether they want the issue fix from TOT which includes many other fixes, Or they just want to have this issue fix over the p162 release only?

By the way, I also sent an email to Arcadyan and add you in the copy list, so that we can receive feedback ASAP and start the process of official release. Hope it does not bother you too much.

Thanks,

Christine.

[virti_choksi]

Hello @Christine_Li, 

FYI, the customer is still facing some issues with the fix you provided, so we are still testing it further. Our testing is not completed yet.

Best Regards, 

Virti Choksi,

[Christine_Li]

Hi, @virti_choksi 

But you have mentioned that the PVT firmware test results are positive—the firmware is working well, and haven't encountered any issues during the evaluation. Is there any confusion between us? Or there is some gap between your test results and Arcadyan's test results?

This PVT firmware is only for test purposes for this issue and it shouldn't be used for any other verification or test purpose. It could fail for any other scenarios or test cases except this issue case.

Best regards,

Christine.

[Christine_Li]

Hi, @virti_choksi 

Do you forget to attach logs?

Would you mind help to share the script that enable and disable Bluetooth?

If you don't attach it on the public community, please think about send to my private working email: christine.li@nxp.com

Best regards,

Christine.

[virti_choksi]

Hello @Christine_Li,

My apologies for the oversight in not attaching the logs to the ticket earlier. I've rectified this by attaching the logcat log file and the Bluetooth toggle script below for your reference and review.

Best Regards,

Virti Choksi

[Christine_Li]

Hi, @virti_choksi 

Thanks for providing logs.

From your given logs, I can only see below key info, and the issue seems to be host side issue.

=====================

01-05 01:00:06.646 635 728 E WifiVendorHal: getWifiLinkLayerStats_1_5_Internal(l.1191) failed {.code = ERROR_UNKNOWN, .description = unknown error}
01-05 01:00:07.109 18528 18553 E bt_hci : system/bt/hci/src/hci_layer.cc:379 startup_timer_expired: startup_timer_expired
01-05 01:00:07.109 18528 18553 I BtStopWatchLegacy: system/bt/common/stop_watch_legacy.cc:58 DumpStopWatchLog: =====================================
01-05 01:00:07.109 18528 18553 I BtStopWatchLegacy: system/bt/common/stop_watch_legacy.cc:59 DumpStopWatchLog: bluetooth stopwatch log history:
01-05 01:00:07.109 18528 18553 I BtStopWatchLegacy: system/bt/common/stop_watch_legacy.cc:86 DumpStopWatchLog: =====================================
01-05 01:00:07.109 379 379 I android.hardware.bluetooth@1.0-impl: BluetoothHci::close()
01-05 01:00:07.109 379 379 D android.hardware.bluetooth@1.0-impl: low_power_mode_cb result: 0
01-05 01:00:07.111 379 379 I android.hardware.bluetooth@1.0-impl: Firmware configured in 2.896s
--------- beginning of crash
01-05 01:00:07.112 18528 18553 F libc : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 18553 (alarm_default_c), pid 18528 (droid.bluetooth)
01-05 01:00:07.207 18577 18577 I crash_dump32: obtaining output fd from tombstoned, type: kDebuggerdTombstoneProto
01-05 01:00:07.211 243 243 I tombstoned: received crash request for pid 18553
01-05 01:00:07.214 18577 18577 I crash_dump32: performing dump of process 18528 (target tid = 18553)
01-05 01:00:07.264 18577 18577 E DEBUG : failed to read /proc/uptime: Permission denied
01-05 01:00:07.766 18577 18577 W unwind : Failed to initialize DEX file support: dlopen failed: library "libdexfile.so" not found
01-01 13:48:39.954 0 0 I logd : logdr: UID=1002 GID=1002 PID=18577 n tail=0 logMask=8 pid=18528 start=0ns deadline=0ns
01-01 13:48:39.962 0 0 I logd : logdr: UID=1002 GID=1002 PID=18577 n tail=0 logMask=1 pid=18528 start=0ns deadline=0ns
01-05 01:00:08.050 18577 18577 F DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
01-05 01:00:08.050 18577 18577 F DEBUG : Build fingerprint: 'Swisscom/TVBox/IP2000:12/SC/eng.virti.20231205.200816:userdebug/test-keys'
01-05 01:00:08.050 18577 18577 F DEBUG : Revision: '0'
01-05 01:00:08.050 18577 18577 F DEBUG : ABI: 'arm'
01-05 01:00:08.050 18577 18577 F DEBUG : Timestamp: 2024-01-05 01:00:07.263592320+0530
01-05 01:00:08.050 18577 18577 F DEBUG : Process uptime: 0s
01-05 01:00:08.050 18577 18577 F DEBUG : Cmdline: com.android.bluetooth
01-05 01:00:08.050 18577 18577 F DEBUG : pid: 18528, tid: 18553, name: alarm_default_c >>> com.android.bluetooth <<<
01-05 01:00:08.050 18577 18577 F DEBUG : uid: 1002
01-05 01:00:08.050 18577 18577 F DEBUG : signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr --------
01-05 01:00:08.050 18577 18577 F DEBUG : r0 00000000 r1 00004879 r2 00000006 r3 c20e68d8
01-05 01:00:08.050 18577 18577 F DEBUG : r4 c20e68ec r5 c20e68d0 r6 00004860 r7 0000016b
01-05 01:00:08.050 18577 18577 F DEBUG : r8 c20e68d8 r9 c20e68e8 r10 c20e6908 r11 c20e68f8
01-05 01:00:08.050 18577 18577 F DEBUG : ip 00004879 sp c20e68a8 lr ea5458ad pc ea5458c0
01-05 01:00:08.050 18577 18577 F DEBUG : backtrace:
01-05 01:00:08.051 18577 18577 F DEBUG : #00 pc 000388c0 /apex/com.android.runtime/lib/bionic/libc.so (abort+172) (BuildId: 065f5a7b98a8052e1c4af4e537983a0f)
01-05 01:00:08.051 18577 18577 F DEBUG : #01 pc 00202705 /system/lib/libbluetooth.so (startup_timer_expired(void*)+132) (BuildId: 307b16c5ee434f8c03a30f8982dc968a)
01-05 01:00:08.051 18577 18577 F DEBUG : #02 pc 002b0c0d /system/lib/libbluetooth.so (alarm_ready_generic(alarm_t*, std::__1::unique_lock<std::__1::mutex>&)+312) (BuildId: 307b16c5ee434f8c03a30f8982dc968a)
01-05 01:00:08.051 18577 18577 F DEBUG : #03 pc 002b0aa3 /system/lib/libbluetooth.so (alarm_queue_ready(fixed_queue_t*, void*)+62) (BuildId: 307b16c5ee434f8c03a30f8982dc968a)
01-05 01:00:08.051 18577 18577 F DEBUG : #04 pc 002b35bf /system/lib/libbluetooth.so (internal_dequeue_ready(void*)+46) (BuildId: 307b16c5ee434f8c03a30f8982dc968a)
01-05 01:00:08.051 18577 18577 F DEBUG : #05 pc 002b437f /system/lib/libbluetooth.so (run_reactor(reactor_t*, int)+274) (BuildId: 307b16c5ee434f8c03a30f8982dc968a)
01-05 01:00:08.051 18577 18577 F DEBUG : #06 pc 002b424b /system/lib/libbluetooth.so (reactor_start(reactor_t*)+42) (BuildId: 307b16c5ee434f8c03a30f8982dc968a)
01-05 01:00:08.051 18577 18577 F DEBUG : #07 pc 002b541d /system/lib/libbluetooth.so (run_thread(void*)+160) (BuildId: 307b16c5ee434f8c03a30f8982dc968a)
01-05 01:00:08.051 18577 18577 F DEBUG : #08 pc 00080587 /apex/com.android.runtime/lib/bionic/libc.so (__pthread_start(void*)+40) (BuildId: 065f5a7b98a8052e1c4af4e537983a0f)
01-05 01:00:08.051 18577 18577 F DEBUG : #09 pc 00039805 /apex/com.android.runtime/lib/bionic/libc.so (__start_thread+30) (BuildId: 065f5a7b98a8052e1c4af4e537983a0f)
01-05 01:00:08.129 243 243 E tombstoned: Tombstone written to: tombstone_09

===================

Is it possible to provide us: tombstone_09 file and Bluetooth btsnoop log?

Please enable the BT snoop log toggle in Settings->Development options->Enable Bluetooth Snoop logs.

Best regards,

Christine.

[virti_choksi]

I couldn't locate the tombstone_09 file and the Bluetooth btsnoop log file on my local system. Could you provide guidance on where I might find these files?

"Please enable the BT snoop log toggle in Settings->Development options->Enable Bluetooth Snoop logs."
Did you mean that the above steps should be done through the GUI?

Best regards,
Virti Choksi

[Christine_Li]

HI, @virti_choksi 

1. tombstone_09 file should be saved on your device. You can try to find it with find cmd like  below:

find -name "*tombstone*"

Right now if issue is still can be reproduce, the tombstone file might be named another one. Such as:tombstone_10 or tombstone_01, something like this. For details, you can refer to the logcat logs as my previous comment:

01-05 01:00:08.129 243 243 E tombstoned: Tombstone written to: tombstone_09

2."Please enable the BT snoop log toggle in Settings->Development options->Enable Bluetooth Snoop logs."
Did you mean that the above steps should be done through the GUI?

==>Yes, through GUI. On your Android device, you can find this button toggle: Settings->Development options->Enable Bluetooth Snoop logs."

After enable that, then enable Bluetooth. Then the bt_snoop log should be saved in your device.

The default path is: data/misc/bluetooth/logs

But the logs saving path might be different according to different platform. So please have a try with find cmd.

Best regards,

Christine.

[virti_choksi]

Hello @Christine_Li,

Thank you for your response and detailed instructions. I appreciate your assistance in troubleshooting the issue. I'm attaching the requested log files. 

If you require additional details or encounter any specific logs or errors, please let me know.

I have a few queries as mentioned below:

Q1. Is it necessary to enable the developer option to get tombstone logs?

Earlier, when I was attempting to locate it, I couldn't find the log file with the same command. However, after enabling the developer option, I was able to retrieve the log file.

Q2. Can we understand under what circumstances the startup timer expires and what is the root cause of the timer expiration?

Kindly help us to identify and solve the issue. I'm hoping to receive a prompt reply, as this is a critical issue.

Best Regards,

Virti Choksi

[Christine_Li]

Hi, @virti_choksi 

Q1. Is it necessary to enable the developer option to get tombstone logs?

==>Yes, if developer option is disabled, you might not have permission to get this logs.

Q2. Can we understand under what circumstances the startup timer expires and what is the root cause of the timer expiration?

==>It is very complex, and also there are many reasons to cause startup failed. We need to check more to try to get more findings.

Did you firstly enable Bluetooth snoop toggle and then enable Bluetooth to try to reproduce the issue?

If yes, you should get several bt_snoop logs in the directory because you are do stress test to enable and disable BT several times. Enable one time, there should be one bt_snoop.log file generated.

I will check logs and try to find more.

Best regards,

Christine.

[Christine_Li]

Hi, @virti_choksi 

I doubt that our BT is in sleep mode.

Please see my analysis:

Please have a try with below suggestion:

1.When you load BT driver, please add this parameter: psmode=0

Or like below:

echo "psmode=0" > /proc/mbt/hci0/config

To get status:

cat  /proc/mbt/hci0/config to see whether set successfully.

Then test it, and let me know your result.

2. After disable BT, use rmmod command to remove Bluetooth driver and before enable BT, use insmod command to load BT driver again.

Please have  a try, and let me your result.

If above 2 methods still failed, please help to provide: BT_snoop.log+logcat.log and tombstone logs.

Best regards,

Christine.

[virti_choksi]

Hello @Christine_Li,

I followed your suggestion and changed the "psmode=0" configuration. However, upon conducting the test again, there was no significant improvement. Additionally, the test did not complete the 150 cycles of Bluetooth enable/disable. I am attaching the log below for your reference.

I will proceed with method 2 and update you regarding the outcome. 

Your assistance in identifying and resolving this issue is greatly appreciated. Given the critical nature of the problem, I'm hoping to receive a prompt reply.

Thank you.

Best Regards,

Virti Choksi

[Christine_Li]

Hi, @virti_choksi 

Thanks for your trial.

I checked your new logs based on the method 1 to set psmode=0.

Yes, from the given logs, I saw you have set psmode=0 successfully, but still failed with same reason.

It looks like our FW doesn't response in time and result in tombstone. 

Please see below my analysis.
===========

Successful scenario:

01-15 23:01:27.463 373 373 I hardware_nxp: Sending hci command 0x0C03 (hw_bt_send_reset)
01-15 23:01:27.871 373 11374 I hardware_nxp: Reply received for command 0x0C03 (hw_bt_send_reset) status 0x00

Failed scenario:
01-15 23:07:30.980 373 373 I hardware_nxp: Sending hci command 0x0C03 (hw_bt_send_reset)

01-15 23:07:33.856 11525 11550 E bt_hci : system/bt/hci/src/hci_layer.cc:379 startup_timer_expired: startup_timer_expired

==============

Please have a try with the second method, and let me know your result.

If still failed, please provide me same logs.

At the same time, I will also discuss this issue with our internal team to see what happened in the firmware side.

Best regards,

Christine.

[virti_choksi]

Hello @Christine_Li,

I have followed the steps outlined in method 2, disabling Bluetooth using rmmod and re-enabling it using insmod. Unfortunately, it appears that the issue persists.

I have attached the complete logs for your reference.

Have there been any responses from the internal team regarding the firmware side about the root cause of the startup timer expire?

Best Regards,

Virti Choksi

[Christine_Li]

Hi, @virti_choksi 

Thanks for trying our suggestions.

But from your given logs, I saw that you only rmmod and insmod once before the stress test.

It is my mistake to let you misunderstand my meaning.

I mean during the stress test, 

svc bluetooth disable

rmmod bt8xxx.ko

insmod /vendor/lib/modules/bt8xxx.ko

svc bluetooth enable

I checked your logs, if I am correct, you only rmmod and insmod one time before the stress test.

Am I right?

We are still under discussion with our internal team.

And I also have escalated to our AE team and created an internal case. 

Best regards,

Christine.

[virti_choksi]

Hi @Christine_Li,

I appreciate the clarification, and I apologize for any misunderstanding. You are correct; I only performed the rmmod and insmod once before the stress test. Thank you for pointing that out.

To ensure accurate testing, I will repeat the stress test with the updated steps and provide you with the corresponding logs.

Your efforts in escalating the issue to the internal AE team are highly appreciated. Given the critical nature of this issue, we aim to resolve it as early as possible. Thank you for your dedication and support.

Best Regards,

Virti Choksi

[Christine_Li]

Hi, @virti_choksi 

Yes, please help to share your test results after update the steps with adding rmmod and insmod command at each time of disable and enable.

And I also received our internal AE team's feedback as below:
============

We have checked the shared log, and from the logs, we can see that there is no response to the reset command, to check if the firmware is properly downloaded or not we required the logcat logs with the vhal_trace_level = 5, and to check the command behavior we required the UART capture.

So, please share the logcat logs with vhal_trace_level=5 and UART capture to proceed further on this.

================

Best regards,

Christine.