版本: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第一次调用该方法,也会有延迟。
解决方案:我们的解决方案是提前创建该对象,使用的时候就不会有延迟了。
|