1.问题背景

测试同学在测试的时候发现蓝牙无法自动连接,然后就尝试开/关蓝牙开关按钮来测试是否能重新自动连上蓝牙。但是结果是一直连接不上。

后来在/data/tombstone中发现很多墓碑日志,于是就导出给到我这边分析。

墓碑日志原始文件见附件中。此处描述分析过程。分析过程中主要会使用到:addr2line, objdump, ndk-stack工具。(具体使用方法在《addr2line, objdump, ndk-stack使用方法》中介绍)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
pid: 18459, tid: 18480, name: BT Service Call  >>> com.android.bluetooth <<<
signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x84d20a5cc8
x0 00000084d20a5cc8 x1 00000074d218f930 x2 00000074d2000000 x3 0000000000000003
x4 000000000000018f x5 0000000000000000 x6 2e73612e6c647372 x7 7f7f7f7f7f7f7f7f
x8 00000074bff8e370 x9 235a76edc05fe912 x10 000000000000018f x11 382d303030312d30
x12 303830302d303030 x13 6266343362396635 x14 0000000000000000 x15 00000074bff8db08
x16 000000755bcf3be0 x17 000000755bc86174 x18 0000000000000001 x19 00000074d20a5cd8
x20 00000000ffffffff x21 00000074c093b6d9 x22 00000074c093b6ed x23 00000074c093b6fc
x24 00000074c093b721 x25 0000000000000000 x26 0000000000000001 x27 00000074c0a37000
x28 00000074bff8e371 x29 00000074bff8e350
sp 00000074bff8e300 lr 00000074c06d338c pc 00000074c090fe1c

backtrace:
#00 pc 00000000003bce1c /system/lib64/libbluetooth.so (bluetooth::Uuid::ToString() const+12)
#01 pc 0000000000180388 /system/lib64/libbluetooth.so (checkIOSDevice(unsigned int, bluetooth::Uuid*) [clone .cfi]+136)
#02 pc 000000000018442c /system/lib64/libbluetooth.so (btif_dm_search_services_evt(unsigned short, char*) [clone .cfi]+1388)
#03 pc 000000000017cfbc /system/lib64/libbluetooth.so (bt_jni_msg_ready(void*) [clone .cfi]+136)
#04 pc 0000000000096908 /system/lib64/libchrome.so (base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)+248)
#05 pc 00000000000afd14 /system/lib64/libchrome.so (base::MessageLoop::RunTask(base::PendingTask*)+416)
#06 pc 00000000000affbc /system/lib64/libchrome.so (base::MessageLoop::DeferOrRunPendingTask(base::PendingTask)+52)
#07 pc 00000000000b03f8 /system/lib64/libchrome.so (base::MessageLoop::DoWork()+380)
#08 pc 00000000000b1790 /system/lib64/libchrome.so (base::MessagePumpDefault::Run(base::MessagePump::Delegate*)+180)
#09 pc 00000000000afa08 /system/lib64/libchrome.so (base::MessageLoop::RunHandler()+112)
#10 pc 00000000000cc60c /system/lib64/libchrome.so (base::RunLoop::Run()+136)
#11 pc 000000000017d54c /system/lib64/libbluetooth.so (run_message_loop(void*) [clone .cfi]+348)
#12 pc 00000000002b6164 /system/lib64/libbluetooth.so (work_queue_read_cb(void*) [clone .cfi]+120)
#13 pc 00000000002b460c /system/lib64/libbluetooth.so (run_reactor(reactor_t*, int) [clone .cfi]+416)
#14 pc 00000000002b4440 /system/lib64/libbluetooth.so (reactor_start(reactor_t*) [clone .cfi]+84)
#15 pc 00000000002b5f14 /system/lib64/libbluetooth.so (run_thread(void*) [clone .cfi]+188)
#16 pc 00000000000819b4 /system/lib64/libc.so (__pthread_start(void*)+36)
#17 pc 0000000000023478 /system/lib64/libc.so (__start_thread+68)

// 以下信息以简述描述
// 栈信息
// 各个寄存器附近的内存信息
// 崩溃附近的log日志
// 各个线程栈信息
// 崩溃附近的所有线程的日志信息
--------- log main
09-13 15:40:03.952 18459 18500 W bt_btm_ble: btm_ble_process_adv_pkt_cont device no longer discoverable, discarding advertising packet
09-13 15:40:03.967 18459 18500 W bt_btm_ble: btm_ble_process_adv_pkt_cont device no longer discoverable, discarding advertising packet
09-13 15:40:04.006 18459 18480 D bt_btif_config: btif_get_device_type: Device [b8:c7:4a:77:58:1e] type 1
09-13 15:40:04.007 18459 18480 W BluetoothRemoteDevices: Skip name update for B8:C7:4A:77:58:1E
09-13 15:40:04.007 18459 18480 W BluetoothRemoteDevices: Skip class update for B8:C7:4A:77:58:1E
09-13 15:40:04.016 18459 18500 W bt_btm_ble: btm_ble_process_adv_pkt_cont device no longer discoverable, discarding advertising packet
09-13 15:40:04.131 18459 18500 W bt_btm_ble: btm_ble_process_adv_pkt_cont device no longer discoverable, discarding advertising packet
09-13 15:40:04.140 18459 18500 W bt_btm_ble: btm_ble_process_adv_pkt_cont device no longer discoverable, discarding advertising packet
09-13 15:40:04.142 18459 18480 D bt_btif_config: btif_get_device_type: Device [e0:cc:f8:71:cd:0b] type 1
09-13 15:40:04.142 18459 18480 W BluetoothRemoteDevices: Skip name update for E0:CC:F8:71:CD:0B
09-13 15:40:04.142 18459 18480 W BluetoothRemoteDevices: Skip class update for E0:CC:F8:71:CD:0B
09-13 15:40:04.156 18459 18500 W bt_btm_ble: btm_ble_process_adv_pkt_cont device no
......

2.调查过程

从日志信息中,我们首先看日志前几行,定位哪个应用,那种类型的错误。

1
2
pid: 18459, tid: 18480, name: BT Service Call  >>> com.android.bluetooth <<<
signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x84d20a5cc8

从以上信息可以看出问题发生在BT Service Call中,包名为: com.android.bluetooth

错误类型是:SIGSEGV段错误,内存地址指向:0x84d20a5cc8

确定应用和错误类型之后,开始分析trace文件

1
2
3
4
#00 pc 00000000003bce1c  /system/lib64/libbluetooth.so (bluetooth::Uuid::ToString() const+12)
#01 pc 0000000000180388 /system/lib64/libbluetooth.so (checkIOSDevice(unsigned int, bluetooth::Uuid*) [clone .cfi]+136)
#02 pc 000000000018442c /system/lib64/libbluetooth.so (btif_dm_search_services_evt(unsigned short, char*) [clone .cfi]+1388)
#03 pc 000000000017cfbc /system/lib64/libbluetooth.so (bt_jni_msg_ready(void*) [clone .cfi]+136)

从trace文件中可以看到应用最终崩溃在pc指针指向00000000003bce1c地址上。方法是调用bluetooth::Uuid::ToString(),bluetooth::Uuid指向的地址是一个错误的内存地址。

然后使用addr2line工具,找到带有符号表的libbluetooth.so。

注意:千万不要导出车机系统中/system/lib64/下的libbluetooth.so库,因此该so库没有符号表,根本看不出来是那行函数报错了。

实际:在源码编译完成之后的out目录下取找带有符号表的so库。路径在:out/target/product/msmnile_gvmq/obj/SHARED_LIBRARIES/<模块名_intermediates>/LINKED/中。

1
2
3
4
5
6
7
8
9
# addr2line -aCfe libbluetooth.so 3bce1c
0x00000000003bce1c
bluetooth::Uuid::ToString() const
system/bt/types/bluetooth/uuid.cc:169

# addr2line -aCfe libbluetooth.so 180388
0x0000000000180388
checkIOSDevice(unsigned int, bluetooth::Uuid*)
system/bt/btif/src/btif_dm.cc:1377

可以看到system/bt/btif/src/btif_dm.cc的1377行报错。

然后在1377行调用system/bt/types/bluetooth/uuid.cc的169行报错。

然后再源码中找到对应的代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
#define IAP_UUID "fecacade-afde-cade-defa-cade00000000"
#define IAP_UUID_REV "00000000-deca-fade-deca-deafdecacafe"
bool checkIOSDevice( uint32_t num_uuids, bluetooth::Uuid* p_uuid_list ) {
bluetooth::Uuid* p_temp_uuidlist = p_uuid_list;
bool bresult = false;
uint32_t i = num_uuids - 1;
for (; i >=0; i--) {
std::string temp = p_temp_uuidlist[i].ToString(); // 1377行报错
// p_temp_uuidlist[i]对应的对象是bluetooth::Uuid
BTIF_TRACE_DEBUG("%s: :uuid[%d] = %s",
__func__, i, temp.c_str() );
if( 0 == temp.compare(IAP_UUID) ||
0 == temp.compare(IAP_UUID_REV) ) {
bresult = true;
break;
}
}

return bresult;
}
#endif

其实从这里已经可以基本判断是那里错误了,就是p_temp_uuidlist[i]指向的对象是一个错误的地址。那现在到地址哪个i导致报错的呢。在继续追溯以下向上调用栈。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
// android/system/bt/btif/src/btif_dm.cc 
static void btif_dm_search_services_evt(uint16_t event, char* p_param) {
tBTA_DM_SEARCH* p_data = (tBTA_DM_SEARCH*)p_param;

BTIF_TRACE_EVENT("%s: event = %d", __func__, event);
switch (event) {
case BTA_DM_DISC_RES_EVT: {
bt_property_t prop;
uint32_t i = 0;
bt_status_t ret;

......

prop.type = BT_PROPERTY_UUIDS;
prop.len = 0;
if ((p_data->disc_res.result == BTA_SUCCESS) &&
(p_data->disc_res.num_uuids > 0)) {
prop.val = p_data->disc_res.p_uuid_list;
prop.len = p_data->disc_res.num_uuids * Uuid::kNumBytes128;
// 遍历扫描到的设备uuid
for (i = 0; i < p_data->disc_res.num_uuids; i++) {
std::string temp = ((p_data->disc_res.p_uuid_list + i))->ToString();
LOG_INFO(LOG_TAG, "%s index:%d uuid:%s", __func__, i, temp.c_str());
}
}

......
此处省略部分代码
......

if (p_data->disc_res.num_uuids != 0) {
/* Also write this to the NVRAM */
#ifdef BTIF_VENDOR_CHK_IOS_DEVICE
// 如果有uuid就传入uuid的个数和uuid list
if (checkIOSDevice(p_data->disc_res.num_uuids, p_data->disc_res.p_uuid_list)) {
BTIF_TRACE_WARNING("%s:IOS device don't response carplay uuid when search services,"
" so do not report uuids when get_remote_services", __func__);
break;
}
#endif
ret = btif_storage_set_remote_device_property(&bd_addr, &prop);
ASSERTC(ret == BT_STATUS_SUCCESS, "storing remote services failed",
ret);
/* Send the event to the BTIF */
HAL_CBACK(bt_hal_cbacks, remote_device_properties_cb, BT_STATUS_SUCCESS,
&bd_addr, 1, &prop);
}
} break;

......

default: { ASSERTC(0, "unhandled search services event", event); } break;
}
}

从上面代码可以看出两个问题:

  • btif_dm_search_services_evt()方法中所有没有加锁
  • checkIOSDevice()传入的list在取出元素的时候没有判空。

充满好奇心的程序员想知道到底是在遍历哪一个元素的时候报的问题。可以查看以下具体的日志文件或者寄存器信息。如果有日志,就可以看看日志文件,简单一点,没有日志,就只能寄存器。

看看源码,在搜到设备的时候就有日志打出。

1
2
3
4
for (i = 0; i < p_data->disc_res.num_uuids; i++) {
std::string temp = ((p_data->disc_res.p_uuid_list + i))->ToString();
LOG_INFO(LOG_TAG, "%s index:%d uuid:%s", __func__, i, temp.c_str());
}

在checkIOSDevice()中遍历设备信息的时候也有日志打出

1
2
3
4
5
6
7
8
9
10
for (; i >=0; i--) {
std::string temp = p_temp_uuidlist[i].ToString();
BTIF_TRACE_DEBUG("%s: :uuid[%d] = %s",
__func__, i, temp.c_str() );
if( 0 == temp.compare(IAP_UUID) ||
0 == temp.compare(IAP_UUID_REV) ) {
bresult = true;
break;
}
}

因此,需要看看这部分输出情况。

从trace文件最后的log信息可以看到。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
09-13 15:40:12.313 18459 18500 W bt_sdp  : sdp_copy_raw_data: list_len:1478 cpy_len:1478 p:0x74d212100b p_ccb:0x74c0b47820 p_db:0x74d21dcc88 raw_size:4096 raw_used:0 raw_data:0x74c0a50fd8
09-13 15:40:12.410 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:0 uuid:0000110a-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:1 uuid:00001105-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:2 uuid:00001115-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:3 uuid:00001116-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:4 uuid:0000112f-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:5 uuid:00001112-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:6 uuid:0000111f-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:7 uuid:00001132-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:8 uuid:00000000-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:9 uuid:00000000-0000-1000-8000-00805f9b34fb
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:10 uuid:11c8b310-80e4-4276-afc0-f81590b2177f
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:11 uuid:8ce255c0-200a-11e0-ac64-0800200c9a66
09-13 15:40:12.411 18459 18480 I bt_btif_dm: btif_dm_search_services_evt index:12 uuid:9664aa26-d76c-43ad-9775-d310f253a408
//btif_dm_search_services_evt()方法打印出扫描出来的设备信息
//checkIOSDevice()没有打印设备信息。然后结合checkIOSDevice()代码遍历列表的逻辑是从数组最后元素开始遍历,因此问题就可以断定了:在checkIOSDevice()遍历数组之前,btif_dm_search_services_evt()遍历结束之后,p_temp_uuidlist被修改过,导致checkIOSDevice()遍历时最后一个元素已经不存在了。所以就导致内存越界crash。
09-13 15:40:12.411 18459 18480 D bt_btif_config: btif_get_device_type: Device [18:70:3b:a3:45:5f] type 1
09-13 15:40:12.411 18459 18480 I bt_btif_dm: get_cod remote_cod = 0x005a020c
09-13 15:40:12.411 18459 18480 I BluetoothBondStateMachine: bondStateChangeCallback: Status: 0 Address: 18:70:3B:A3:45:5F newState: 2

问题定论:遍历校验扫描出来的设备信息的时候,因为没有加锁,导致p_temp_uuidlist在另外线程修改过,然后checkIOSDevice()取出的元素是一个未知的内存地址。然后调用toString()崩溃了。

3.解决方案

3.1 在遍历设备的时候加个互斥锁。防止其他线程在遍历校验设备信息的时候,对p_temp_uuidlist数组的修改。

3.2 在p_temp_uuidlist取出元素的时候,判断以下是否存在该元素,如果不存在就不调用toString()方法。

4.附加信息

如果需要使用objdump查看反编译的汇编代码,需要使用编译后的objdump.

路径: prebuilts/gcc/linux-x86/aarch64/aarch64-linux-android-4.9/bin/aarch64-linux-androidkernel-objdump