phhusson / treble_experimentations

Notes about tinkering with Android Project Treble
3.37k stars 659 forks source link

Bluetooth keeps stopping issue (Huawei P8 Lite 2017 - PRA-LX1) #376

Open GianlucaPolcino opened 5 years ago

GianlucaPolcino commented 5 years ago

Bluetooth keeps crashing randomically on my P8 Lite 2017 (and this is my only problem with this ROM :)) This is the log: bluetoothcrash.txt

phhusson commented 5 years ago

Here is relevant extract of the log:

01-22 22:54:14.986 D/bt_btif_config(28564): btif_get_address_type: Device [fa:f7:86:15:38:59] address type 1 01-22 22:54:14.986 D/bt_btif_config(28564): btif_get_device_type: Device [fa:f7:86:15:38:59] type 2 01-22 22:54:14.987 I/bt_stack(28564): [INFO:gatt_api.cc(1109)] GATT_Connectgatt_if=7 fa:f7:86:15:38:59 01-22 22:54:14.989 W/bt_stack(28564): [WARNING:btm_ble.cc(2024)] LE Create Connection attempt failed, status=0x0c 01-22 22:54:14.989 F/bt_stack(28564): [FATAL:btm_ble.cc(2032)] LE Create Connection - command disallowed

@elpollol could you describe your bluetooth systems? Like what devices do you have connected? Are you doing anything specific at the moment it crashes? Were you playing music?

GianlucaPolcino commented 5 years ago

I wear a Mi Band 3... Don't hate me pls Jokes aside, the band works. Like I said, those crashes are pretty random. I play music with a pair of bluetooth headset though, they work without problems

phhusson commented 5 years ago

the crashes appear only when playing music? I think that you should be able to reproduce the issue by simply forcing Mi Band to refresh data while playing music over Bluetooth. Can you try that? If it doesn't crash, then have music playing on Bluetooth and move your band away enough for it to disconnect and come close again to reconnect

Le mar. 22 janv. 2019 à 23:47, elpollol notifications@github.com a écrit :

I wear a Mi Band 3... Don't hate me pls Jokes aside, the band works. Like I said, those crashes are pretty random. I play music with a pair of bluetooth headset though, they work without problems

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/phhusson/treble_experimentations/issues/376#issuecomment-456593254, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAOOlGsLpo0W1EjO0k68KqV0gax0JE4ks5vF5UCgaJpZM4aNppp .

GianlucaPolcino commented 5 years ago

Nope, they appears without playing music. It's only the band I suppose. I tried to get the band away and then to get it close to the phone again: doesn't crash

UPDATE I just find an interesting fact: I can stop the crashing loop opening Mi Fit application and simply waiting the pairing.

penn5 commented 5 years ago

I have the same issue on my Honor 9 Lite. It crashes mostly while playing music (more often then) but can happen at any time. The sympton is that Bluetooth toggles off and on again. I remember at one point i got logs for dil3mm4, and it was a native crash. I'll see if i can find them and upload. It usually happens when multiple devices are connected (I think) but tbh its pretty random. It is not caused by a device connect or disconnect.

penn5 commented 5 years ago

Just googling for the issue, i found this. https://github.com/noble/noble/issues/658. Perhaps the adapter Huawei have used in hi6250 doesn't support scanning and connecting at the same time?

DaveidWeba commented 5 years ago

Using a Huawei Mate SE (essentially a Honor 7X) I can stream Bluetooth audio to a car just fine, but connecting a Honor Band 4 or other devices such as hotel rooms via Hilton's Digital Key, Bluetooth is constantly crashing and unable to successfully pair. Here's two identical logs of the crash: https://del.dog/owupadefex https://del.dog/agaxehusir

If there's any other data I can provide to help resolve this issue, let me know. Thank you

penn5 commented 5 years ago
               << loghex(status);

  if (status == HCI_ERR_COMMAND_DISALLOWED) {
    /* There is already either direct connect, or whitelist connection
     * pending, but we don't know which one, or to which state should we
     * transition now. This can be triggered only in case of rare race
     * condition. Crash to recover. */
    LOG(FATAL) << "LE Create Connection - command disallowed";
  }
penn5 commented 5 years ago

Reverting system/bt#f8e8c59bcb6443651fdafbccbf24910cf84ed0fe should fix it but isn't the root cause. It would just prevent the crash (meaning only the device that caused the crash ends up in a weird state, rather than the entire bluetooth service restarting).

penn5 commented 5 years ago

From: Hackintosh 5 <penn.mackintosh@gmail.com>
Date: Thu, 7 Feb 2019 20:09:42 +0000
Subject: [PATCH] Try to fix huawei messups

---
 hci/src/hci_layer.cc | 14 ++++++++++++++
 1 file changed, 14 insertions(+)

diff --git a/hci/src/hci_layer.cc b/hci/src/hci_layer.cc
index f1e0e7a60..25303843c 100644
--- a/hci/src/hci_layer.cc
+++ b/hci/src/hci_layer.cc
@@ -533,6 +533,20 @@ static void command_timed_out(void* original_wait_entry) {
     LOG_EVENT_INT(BT_HCI_TIMEOUT_TAG_NUM, HCI_UNKNOWN_COMMAND_TIMED_OUT);
   } else {
     command_timed_out_log_info(original_wait_entry);
+
+    for (const list_node_t* node = list_begin(commands_pending_response);
+      node != list_end(commands_pending_response); node = list_next(node)) { //We iterate over all pending commands, and when we get to one that is the same one that timed out, we check if it is a Huawei messup or not.
+    waiting_command_t* wait_entry =
+        reinterpret_cast<waiting_command_t*>(list_node(node));
+      if (wait_entry == original_wait_entry) { //We only care about the actual error.
+        if (wait_entry->opcode == 0x804) {
+          LOG_ERROR(LOG_TAG, "%s: ignoring a Huawei error (opcode=0x%x).", __func__, wait_entry->opcode);
+          lock.unlock();
+          return; //We don't care about Huawei. They want to kill us.
+        }
+      }
+    }
+
     lock.unlock();
   }

-- 
2.17.1

for system/bt
this might fix it im not sure yet
penn5 commented 5 years ago

opcode 0x804 on my device snoop logs is almost always data from Wear OS, which is why smartwatch users see this bug more often (i think)

penn5 commented 5 years ago

opcode 0x804 is Exit Sniff Mode according to wireshark. In my HCI log in Wireshark, it seems that there is a delay of 300ms in normal scenarios, but sometimes it takes up to 4500ms. I've increased the timeout for 0x804 to 5000ms, see patch below.

From: Hackintosh 5 <penn.mackintosh@gmail.com>
Date: Fri, 8 Feb 2019 09:31:51 +0000
Subject: [PATCH] Fix huawei timeouts

---
 hci/src/hci_layer.cc | 14 ++++++++------
 1 file changed, 8 insertions(+), 6 deletions(-)

diff --git a/hci/src/hci_layer.cc b/hci/src/hci_layer.cc
index f1e0e7a60..9a6e36f33 100644
--- a/hci/src/hci_layer.cc
+++ b/hci/src/hci_layer.cc
@@ -78,6 +78,8 @@ static const int BT_HCI_RT_PRIORITY = 1;

 // Abort if there is no response to an HCI command.
 static const uint32_t COMMAND_PENDING_TIMEOUT_MS = 2000;
+// But let the buggy Huawei commands have a longer timeout so we don't crash if there is no error.
+static const uint32_t HUAWEI_COMMAND_PENDING_TIMEOUT_MS = 5000;
 static const uint32_t COMMAND_PENDING_MUTEX_ACQUIRE_TIMEOUT_MS = 500;
 static const uint32_t COMMAND_TIMEOUT_RESTART_MS = 5000;
 static const int HCI_UNKNOWN_COMMAND_TIMED_OUT = 0x00ffffff;
@@ -127,7 +129,7 @@ static void enqueue_packet(void* packet);
 static void event_packet_ready(void* packet);
 static void command_timed_out(void* context);

-static void update_command_response_timer(void);
+static void update_command_response_timer(int opcode);

 static void transmit_fragment(BT_HDR* packet, bool send_transmit_finished);
 static void dispatch_reassembled(BT_HDR* packet);
@@ -430,7 +432,7 @@ static void event_command_ready(waiting_command_t* wait_entry) {
   // Send it off
   packet_fragmenter->fragment_and_dispatch(wait_entry->command);

-  update_command_response_timer();
+  update_command_response_timer(wait_entry->opcode);
 }

 static void enqueue_packet(void* packet) {
@@ -623,7 +625,7 @@ static bool filter_incoming_event(BT_HDR* packet) {
                  __func__, opcode);
       }
     } else {
-      update_command_response_timer();
+      update_command_response_timer(wait_entry->opcode);
       if (wait_entry->complete_callback) {
         wait_entry->complete_callback(packet, wait_entry->context);
       } else if (wait_entry->complete_future) {
@@ -650,7 +652,7 @@ static bool filter_incoming_event(BT_HDR* packet) {
           "%s command status event with no matching command. opcode: 0x%04x",
           __func__, opcode);
     } else {
-      update_command_response_timer();
+      update_command_response_timer(wait_entry->opcode);
       if (wait_entry->status_callback)
         wait_entry->status_callback(status, wait_entry->command,
                                     wait_entry->context);
@@ -725,7 +727,7 @@ static int get_num_waiting_commands() {
   return list_length(commands_pending_response);
 }

-static void update_command_response_timer(void) {
+static void update_command_response_timer(int opcode) {
   std::lock_guard<std::recursive_timed_mutex> lock(
       commands_pending_response_mutex);

@@ -733,7 +735,7 @@ static void update_command_response_timer(void) {
   if (list_is_empty(commands_pending_response)) {
     alarm_cancel(command_response_timer);
   } else {
-    alarm_set(command_response_timer, COMMAND_PENDING_TIMEOUT_MS,
+    alarm_set(command_response_timer, (opcode == 0x804) ? HUAWEI_COMMAND_PENDING_TIMEOUT_MS : COMMAND_PENDING_TIMEOUT_MS,
               command_timed_out, list_front(commands_pending_response));
   }
 }
-- 
2.17.1
penn5 commented 5 years ago

Interesting, for testing this, opening either Spotify for Wear OS both force a transition to to non-sniff mode. But the timeout only seems to happen when playing music.

phhusson commented 5 years ago

@elpollol said "Nope, they appears without playing music."

penn5 commented 5 years ago

I know... I guess there is just a lot more activity while playing music, so the timeout is more likely to happen then? TBH IDK.

phhusson commented 5 years ago

@penn5 this issue can be fixed with your magic bluetooth properties now, right?

penn5 commented 5 years ago

Yep, setprop persist.sys.bt.unsupport.states 000000000000000000000011111 and setprop persist.sys.bt.unsupport.features 00000001 should fix it.

Dil3mm4 commented 5 years ago

This should be closed imho

penn5 commented 5 years ago

@phhusson

This should be closed imho

alonevino commented 5 years ago

I confirm issues with bluetooth calls both incoming and outgoing in every AOSP based ROM; I'm pairing flawlessly but as soon as I connect with a call BT reverts back.

penn5 commented 5 years ago

I confirm issues with bluetooth calls both incoming and outgoing in every AOSP based ROM; I'm pairing flawlessly but as soon as I connect with a call BT reverts back.

That's not related to this issue. Please open a separate one and mention it here so I can find it.

aintnobodygottimeforthat commented 5 years ago

Hi, I also have a similar issue on Huawei P8 Lite 2017 - PRA-LX1 with Xiaomi Mi Band 3, but the problems occur much sooner - I am unable to pair from within the app.

I believe the relevant part is this 09-03 21:11:29.683 6000 14737 D BluetoothGatt: connect() - device: C7:8E:D9:10:81:6E, auto: false 09-03 21:11:29.684 6000 14737 D BluetoothGatt: registerApp() 09-03 21:11:29.684 6000 14737 D BluetoothGatt: registerApp() - UUID=48f41091-b046-4c8d-ab99-98eaa6d822da 09-03 21:11:29.687 14088 14125 I bt_stack: [INFO:gatt_api.cc(948)] GATT_Register e4a83f00-506d-3d91-c26f-c2515a373028 09-03 21:11:29.687 14088 14125 I bt_stack: [INFO:gatt_api.cc(968)] allocated gatt_if=7 09-03 21:11:29.687 6000 6015 D BluetoothGatt: onClientRegistered() - status=0 clientIf=7 09-03 21:11:29.688 14088 14110 D bt_btif_config: btif_get_address_type: Device [c7:8e:d9:10:81:6e] address type 1 09-03 21:11:29.688 14088 14110 D bt_btif_config: btif_get_device_type: Device [c7:8e:d9:10:81:6e] type 2 09-03 21:11:29.688 14088 14125 I bt_stack: [INFO:gatt_api.cc(1109)] GATT_Connectgatt_if=7 c7:8e:d9:10:81:6e 09-03 21:11:29.689 14088 14125 E bt_l2cap: initate direct connection fail, topology limitation 09-03 21:11:29.689 14088 14125 W bt_l2cap: L2CA_ConnectFixedChnl() - create_conn failed 09-03 21:11:29.689 14088 14125 E bt_stack: [ERROR:gatt_main.cc(374)] gatt_connect failed 09-03 21:11:29.689 14088 14125 E bt_stack: [ERROR:bta_gattc_act.cc(357)] Connection open failure 09-03 21:11:29.690 14088 14125 W bt_stack: [WARNING:bta_gattc_act.cc(339)] bta_gattc_open_fail: Cannot establish Connection. conn_id=0. Return GATT_ERROR(133) 09-03 21:11:29.690 6000 6015 D BluetoothGatt: onClientConnectionState() - status=133 clientIf=7 device=C7:8E:D9:10:81:6E 09-03 21:11:29.695 6000 14737 D BluetoothGatt: cancelOpen() - device: C7:8E:D9:10:81:6E 09-03 21:11:29.696 14088 14125 E bt_stack: [ERROR:bta_gattc_act.cc(292)] No such connection need to be cancelled 09-03 21:11:29.696 6000 14737 D BluetoothGatt: close() 09-03 21:11:29.696 6000 14737 D BluetoothGatt: unregisterApp() - mClientIf=7 09-03 21:11:29.696 14088 14125 E bt_stack: [ERROR:bta_gattc_utils.cc(433)] bta_gattc_mark_bg_conn unable to find the bg connection mask for bd_addr=c7:8e:d9:10:81:6e

full log here https://pastebin.com/655UN2BR

ildar commented 2 years ago

Yep, setprop persist.sys.bt.unsupport.states 000000000000000000000011111 and setprop persist.sys.bt.unsupport.features 00000001 should fix it.

@phhusson , this is very much a working solution. Would you please add this as a new workaround to the Settings?

And please no closing this issue until that.

ildar commented 1 year ago

Yep, setprop persist.sys.bt.unsupport.states 000000000000000000000011111 and setprop persist.sys.bt.unsupport.features 00000001 should fix it.

@penn5 this helps but not fully. BT still crashes. I think I may need some other value for unsupport.states for my phone. How can I find out? logcat? btsnoop? plz help.

ildar commented 1 year ago

Unfortunately @TrebleDroid still has the crashy BT stack. Is it at all possible to fix?