如何分析线程池线程唤醒耗时100微秒的深层原因？

我正在对比线程池的两种实现，其中基于锁和条件变量的版本比无锁版本慢约100微秒。从理论上能解释无锁实现更快的原因，但需要获取总运行时间之外的对比数据，明确这100微秒的具体耗时环节。

已定位到性能差距来自主线程调用notify_all唤醒工作线程，到工作线程退出wait开始执行任务的这段时间，当前应用核心逻辑运行时长约1毫秒，测试环境为Linux系统。

较慢的锁+条件变量实现代码片段如下：

void ThreadMain(std::stop_token stoken, ThreadPool* pool,
                std::atomic_flag& start,
                std::vector<ThreadPool::timestamp>& stamps) {
    while (!stoken.stop_requested()) {
        std::unique_lock<std::mutex> lock(pool->mutex);
        pool->mutex_condition.wait(lock, [&] { return start.test(); });
        stamps.push_back(high_resolution_clock::now());
        if (stoken.stop_requested()) {
            return;
        }
        int i{0};
        while ((i = pool->idx.fetch_sub(1) - 1) > -1) {
            (*(pool->task))(pool->ctx, i);
        }
        start.clear();
        if ((pool->completed_tasks.fetch_add(1) + 1) == pool->threads.size()) {
            pool->completed.notify_one();
        }
    }
}


void ThreadPool::QueueTask(ThreadPool::function* function, void* context,
                           int r) {
    {
        std::unique_lock<std::mutex> lock(mutex);
        task = function;
        ctx = context;
        completed_tasks = 0;
        idx.store(r, order);  // ensure that every thread know
        for (std::atomic_flag& start : starts) {
            start.test_and_set();
        }
    }
    mutex_condition.notify_all();
    timestamps[0].push_back(high_resolution_clock::now());
    int i{0};
    while ((i = idx.fetch_sub(1, order) - 1) > -1) {
        (*(function))(context, i);
    }
    {
        std::unique_lock<std::mutex> lock(mutex);
        completed.wait(
            lock, [this] { return completed_tasks.load() == threads.size(); });
        for (std::atomic_flag& flag : starts) {
            flag.clear();
        }
        completed_tasks = 0;
    }
}

一、代码层面加细粒度时间打点 #

在现有时间戳基础上，补充关键节点的时间记录，精准拆分耗时环节：

• 主线程中，记录**mutex_condition.notify_all()调用前/后的时间**，区分锁释放、notify系统调用的耗时
• 工作线程中，记录获取锁完成的时间、进入wait前的时间、退出wait后的时间，拆分锁竞争、条件变量等待、调度唤醒的耗时
• 计算各节点时间差，比如主线程锁释放到notify完成的耗时、工作线程从notify到获取锁的耗时等

二、使用perf工具分析 #

1. 采样锁与调度事件 #

• 追踪锁和条件变量的内核事件：

  perf record -e mutex:mutex_lock,mutex:mutex_unlock,condition_variable:cond_signal,condition_variable:cond_wait -g ./your_program
  

  用perf report查看锁的持有、等待时长，以及条件变量信号传递的耗时占比
• 采样上下文切换：

  perf record -e sched:sched_switch -g ./your_program
  

  重点关注主线程notify后，工作线程被调度唤醒的延迟

2. 统计调度延迟指标 #

用perf stat对比两种实现的调度相关数据：

perf stat -e sched:sched_wakeup,sched:sched_switch,sched:sched_stat_wait ./your_program

关注sched_stat_wait的总时长和平均时长，这反映线程被唤醒后到实际运行的调度延迟

三、用ftrace追踪内核级链路 #

ftrace可以精准追踪条件变量的内核执行路径，明确notify到wait唤醒的全链路耗时：

1. 挂载debugfs（若未挂载）：mount -t debugfs none /sys/kernel/debug
2. 配置追踪规则：

   echo 'function:pthread_cond_broadcast function:pthread_cond_wait' > /sys/kernel/debug/tracing/set_ftrace_filter
   echo function > /sys/kernel/debug/tracing/current_tracer
   echo 1 > /sys/kernel/debug/tracing/tracing_on
   

3. 运行程序后停止追踪并导出结果：

   echo 0 > /sys/kernel/debug/tracing/tracing_on
   cat /sys/kernel/debug/tracing/trace > trace_output.txt
   

4. 在输出中匹配主线程调用pthread_cond_broadcast（对应notify_all）和工作线程pthread_cond_wait返回的时间点，计算时间差并分析中间内核调度逻辑

四、对比无锁实现的关键路径 #

将锁实现的各环节耗时，与无锁实现对应环节做对比：

• 统计无锁实现中线程检测任务就绪的延迟
• 明确100微秒差距主要来自调度延迟，还是锁/条件变量的内核开销

内容的提问来源于stack exchange，提问作者fabian