前言

入职快一个月了，开始在指导下做些事了，本来分配我解决一个死锁问题，突然拉着我解决这个问题（我是负责软总线及适配的），可把我急坏了，日志甩我一大堆，我没见过这种日志，还让我30分钟内找出根因，我人直接傻了，哭死，不过好在有新手保护期，免死金牌一块，哈哈哈。

当然我自己把手上的死锁问题解决了以后还是想看一下这个问题。

准备

我看群里面记录，他们已经找到异常日志的点了，大致是（原日志是内部保密，不对外公开）stopscan那一块线程卡死，只有函数进入的日志，后面的异常及完成日志全部没有触发。

stopscan适配源码

int32_t SoftbusBleDiscoveryStopScan(int32_t scannerId)
{
    LOGI("Enter scannerId=%d", scannerId);
    // 调用启动回调
    if (g_scanChannel[scannerId].scanCallback == NULL ||
        g_scanChannel[scannerId].scanCallback->OnStopScanCallback == NULL) {
        LOGE("invalid param, OnStopScanCallback is null");
        return SOFTBUS_INVALID_PARAM;
    }

    // 线程安全保护
    if (pthread_mutex_lock(&g_scannerLock) != 0) {
        LOGE("lock failed, scannerId=%d", scannerId);
        return SOFTBUS_LOCK_ERR;
    }
    // 扫描器有效性检查
    if (!CheckScanChannelInUsed(scannerId)) {
        LOGE("scanner is not in used=%d", scannerId);
        pthread_mutex_unlock(&g_scannerLock);
        return SOFTBUS_BC_ADAPTER_NOT_IN_USED_FAIL;
    }
    // 状态检查
    if (!g_scanChannel[scannerId].isScanning) {
        LOGE("already stopped, scannerId=%d, btScanId=%d", scannerId, g_scanChannel[scannerId].scannerId);
        pthread_mutex_unlock(&g_scannerLock);
        return SOFTBUS_ALREADY_TRIGGERED;
    }
    pthread_mutex_unlock(&g_scannerLock);

    bool ret = DriverExtendBleScanSwitch(false);
    LOGI("old isScanning: %d", g_scanChannel[scannerId].isScanning);
    if (pthread_mutex_lock(&g_scannerLock) == 0) {  // 更新扫描状态
        g_scanChannel[scannerId].isScanning = !ret;
        LOGI("new isScanning: %d", g_scanChannel[scannerId].isScanning);
        pthread_mutex_unlock(&g_scannerLock);
    }
    LOGI("Stop scanning callback...");
    ScanResultReportData *reportData = (ScanResultReportData *)malloc(sizeof(ScanResultReportData));
    if (reportData == NULL) {
        LOGE("malloc reportData failed, reportData is null");
        return SOFTBUS_ERR;
    }
    reportData->scannerId = scannerId;
    reportData->status = ret ? 0 : 1;
    int ret1 = ThreadPoolAdd(g_threadpool, (task_func_t)ThreadOnStopScanChanged, reportData);
    if (ret1 != THREADPOOL_SUCCESS) {
        LOGE("add task ThreadOnStopScanChanged failed: %d", ret1);
        free(reportData);
    }

    if (!ret) {
        LOGE("stop scan failed");
        if (pthread_mutex_lock(&g_scannerLock) == 0) {  // 更新扫描状态
            g_scanChannel[scannerId].isScanning = true;
            pthread_mutex_unlock(&g_scannerLock);
        }
        return SOFTBUS_ERR;
    }
    LOGI("Finish");
    return SOFTBUS_OK;
}

问题分析

第一步：确认死锁

日志中搜索stopscan，全局就出现一次，往下将这个函数准备的日志打印全部搜索看是不是函数内部异常，只有函数入口的enter打印过，其余的日志全部丢失，日志全局没有崩溃日志打印，就基本确认stopscan没拿到锁g_scannerlock。

第二步：确认startscan正常结束释放锁

搜索日志softbusblestartscan相关日志，相关finish在stopscan之前就完成了，锁已经被释放。

第三步：分析结束

那么锁被谁拿去一直不放？？？我也很奇怪！ai分析，要查看stopscan开始以后的日志，看是哪个函数将锁拿走了。我就去找我的PL，pl和我说问题已经解决了，的确是g_scannerlock的死锁问题，不过大疆的问题，他们那边代码和我们这边不匹配，多写了一把锁导致ABBA死锁。。。

经验总结

1. "日志到哪行就卡到哪行"

StopScan 只有 Enter 没有后续日志，说明卡在 Enter 之后、第一条 LOGE 之前的代码。逐行看代码，中间只有 scanCallback 的 NULL 检查和 pthread_mutex_lock。排除 NULL 检查（会有 LOGE），就只剩 pthread_mutex_lock 死锁。这是定位死锁最有效的方法：找到最后一条日志，看它后面第一行代码是什么。

2. 区分"进程崩溃"和"线程死锁"

两者表现相似——都是没有后续日志。区分方法：

本次排查中，driver_ble_discovery.c 在 11:37:01 之后还有日志，排除了崩溃。

3. 不要被上层日志误导

原始日志中的 listener is null 和 unsubscribedevice end fail 是上层 shareservice 的日志，不是本层 driver_ble_discovery.c 的日志。一开始花了很多时间分析 UnRegisterScanListener 的流程，但实际上 UnRegisterScanListener 根本没被调用。排查时要区分日志来源，不要把不同模块的日志混在一起分析。

4. StopScan/StartScan 的 Enter 日志格式完全一样

两个函数入口都是 LOGI("Enter scannerId=%d", scannerId)，仅凭这条日志无法区分是 StartScan 还是 StopScan。需要结合时间线和上下文判断。建议：入口日志应加上函数名或操作类型以示区分。

5. 多锁场景必须保证锁顺序一致

ABBA 死锁是经典问题。当多个模块各自有一把锁，且存在跨模块调用时，必须保证全局锁顺序一致。本次问题就是大疆新增锁时没有考虑与底层 g_scannerLock 的顺序关系。新增锁时，必须梳理所有跨锁调用路径，确保锁顺序一致。