Android切换希腊语蓝牙打开失败

249 0 0

作者:dreamer-l

版本：Android 9
平台：RK-PX30

问题描述：在状态栏点击蓝牙图标打开蓝牙时，发现打开失败，进入到设置里打开蓝牙却能打开成功，但是时间会比较长。

分析：
查看日志发现，执行BluetoothHci::initialize()后，在获取到蓝牙MAC地址，就又把蓝牙关闭了。测试发现如果把蓝牙开启超时时间设置长点就可以正常打开了（由原本的4s改为10s）。

2021-10-27 14:32:30.561 495-522/system_process D/BluetoothManagerService: MESSAGE_BLUETOOTH_STATE_CHANGE: OFF > BLE_TURNING_ON
2021-10-27 14:32:30.561 495-522/system_process D/BluetoothManagerService: Sending BLE State Change: OFF > BLE_TURNING_ON
2021-10-27 14:32:30.561 19461-19482/com.android.bluetooth D/BluetoothAdapterService: bleOnProcessStart()
2021-10-27 14:32:30.564 19461-19482/com.android.bluetooth D/BluetoothAdapterService: bleOnProcessStart() - Make Bond State Machine
2021-10-27 14:32:30.565 19461-19482/com.android.bluetooth D/BluetoothBondStateMachine: make
2021-10-27 14:32:30.570 19461-19497/com.android.bluetooth I/BluetoothBondStateMachine: StableState(): Entering Off State
2021-10-27 14:32:30.595 19461-19461/com.android.bluetooth D/BluetoothAdapterService: getAdapterService() - returning com.android.bluetooth.btservice.AdapterService@e8fb3e7
2021-10-27 14:32:30.600 19461-19461/com.android.bluetooth D/BluetoothAdapterService: getAdapterService() - returning com.android.bluetooth.btservice.AdapterService@e8fb3e7
2021-10-27 14:32:30.613 19461-19461/com.android.bluetooth D/BluetoothAdapterService: getAdapterService() - returning com.android.bluetooth.btservice.AdapterService@e8fb3e7
2021-10-27 14:32:30.615 19461-19461/com.android.bluetooth D/BluetoothAdapterService: handleMessage() - Message: 2
2021-10-27 14:32:30.615 19461-19461/com.android.bluetooth D/BluetoothAdapterService: handleMessage() - MESSAGE_PROFILE_SERVICE_REGISTERED
2021-10-27 14:32:30.616 19461-19461/com.android.bluetooth D/BluetoothAdapterService: handleMessage() - Message: 1
2021-10-27 14:32:30.616 19461-19461/com.android.bluetooth D/BluetoothAdapterService: handleMessage() - MESSAGE_PROFILE_SERVICE_STATE_CHANGED
2021-10-27 14:32:30.628 19461-19502/com.android.bluetooth I/bt_hci: hci_initialize: IBluetoothHci::getService() returned 0x76f4876c60 (remote)
2021-10-27 14:32:30.628 260-260/? I/android.hardware.bluetooth@1.0-impl: BluetoothHci::initialize()  # 初始化
2021-10-27 14:32:34.566 19461-19482/com.android.bluetooth D/BluetoothAdapterService: updateAdapterState() - Broadcasting state BLE_TURNING_OFF to 1 receivers.
2021-10-27 14:32:34.567 495-522/system_process D/BluetoothManagerService: MESSAGE_BLUETOOTH_STATE_CHANGE: BLE_TURNING_ON > BLE_TURNING_OFF
2021-10-27 14:32:34.567 495-522/system_process D/BluetoothManagerService: Sending BLE State Change: BLE_TURNING_ON > BLE_TURNING_OFF  # 从log的时间来看，过了大概4s就把蓝牙状态设置为关闭，代码中超时时间就是4s
2021-10-27 14:32:34.742 495-495/system_process D/BluetoothManagerService: Bluetooth Adapter address changed to 0F:DD:CC:AA:EE:0A  # 调用的initialize()  4s后才返回结果，但此时状态已经设置为BLE_TURNING_OFF了
2021-10-27 14:32:34.743 495-495/system_process D/BluetoothManagerService: Stored Bluetoothaddress: 0F:DD:CC:AA:EE:0A
2021-10-27 14:32:34.744 495-495/system_process D/BluetoothManagerService: Bluetooth Adapter name changed to IPPhone
2021-10-27 14:32:34.747 495-495/system_process D/BluetoothManagerService: Stored Bluetooth name: IPPhone
2021-10-27 14:32:34.759 19461-19461/com.android.bluetooth D/BluetoothAdapterService: handleMessage() - Message: 1
2021-10-27 14:32:34.759 19461-19461/com.android.bluetooth D/BluetoothAdapterService: handleMessage() - MESSAGE_PROFILE_SERVICE_STATE_CHANGED
2021-10-27 14:32:34.760 19461-19461/com.android.bluetooth D/BluetoothAdapterService: handleMessage() - Message: 3
2021-10-27 14:32:34.760 19461-19461/com.android.bluetooth D/BluetoothAdapterService: handleMessage() - MESSAGE_PROFILE_SERVICE_UNREGISTERED
2021-10-27 14:32:34.761 19461-19482/com.android.bluetooth D/BluetoothAdapterService: updateAdapterState() - Broadcasting state OFF to 1 receivers.
2021-10-27 14:32:34.761 495-522/system_process D/BluetoothManagerService: MESSAGE_BLUETOOTH_STATE_CHANGE: BLE_TURNING_OFF > OFF

继续分析，其他语言使用都正常，为什么只有希腊语会有出现这种情况呢？

对比正常情况，BluetoothHci::initialize()调用后在2s内就会返回结果，因此问题就在于希腊语下BluetoothHci::initialize()的时间过长，这种问题最简单的分析方法就是在可能有耗时较长的地方加log打印时间。
logcat本身会打印时间，如果是没有打印时间的，就需要使用其他方式计算时间了。

最后定位到源码里packages/apps/Bluetooth/src/com/android/bluetooth/Utils.java的getAddressStringFromByte()方法。
这个方法里面很简单，就只是调用了format()方法，但是该方法却卡了至少2~4s的时间，加上其他步骤本身就需要接近2s，而上层BLE开启的超时时间是4s，因此很容易就导致超时而打不开。

继续跟踪format()方法的实现：

format() # libcore/ojluni/src/main/java/java/util/Formatter.java
  ` toString()
    ` toUpperCase() # libcore/libart/src/main/java/java/lang/CaseMapper.java

最终找到根本原因是使用了希腊语的toUpperCase()方法。
该方法实现如下：

public static String toUpperCase(Locale locale, String s, int count) {
    String languageCode = locale.getLanguage();
    if (languageCode.equals("tr") || languageCode.equals("az") || languageCode.equals("lt")) {
        return ICU.toUpperCase(s, locale);
    }
    if (languageCode.equals("el")) { // 希腊语使用特殊方法处理
        return EL_UPPER.get().transliterate(s);
    }
}

private static final ThreadLocal<Transliterator> EL_UPPER = new ThreadLocal<Transliterator>() {
    @Override protected Transliterator initialValue() {
        return Transliterator.getInstance("el-Upper");
    }
};

android使用开源转换库icu做处理，在调用希腊语转换模块的时候需要生成大量的对象，因此第一次调用会有很明显的延迟。
经过验证，如果对toUpperCase()指定其他语言，也不会存在延迟；并且其他APP第一次调用该方法，也会有延迟。

解决方案：我们的解决方案是提前创建该对象，使用的时候就不会有延迟了。