追踪内核中神秘的高优先级线程挂起

Question

描述

我正在开发一个嵌入式Linux系统（使用内核3.4和bionic，类似于Android），它运行在多核ARMv7a SoC上。我们有一个用户空间线程，主要服务于内核产生的事件。这些事件是从IRQ生成的，并且必须由用户空间以非常低的延迟进行响应。

一个线程以SCHED_FIFO优先级0运行。它是系统中唯一的优先级0线程。 大致代码如下：

    while (1)
    {
        struct pollfd fds[1];
        fds[0].fd = fd;
        fds[0].events = POLLIN|POLLRDNORM|POLLPRI;

        int ret = poll(fds, 1, reallyLongTimeout);
        FTRACE("poll() exit");
        if (ret > 0)
        {
            // notify worker threads of pending events
        }
    }

通常我们能获得非常好的延迟（线程在毫秒内完成轮询并返回到 poll()），但是有时会出现延迟十几毫秒的情况，这会破坏一切。在全面跟踪后，我得出结论：延迟发生在中断触发后 poll() 系统调用返回之前，因为线程自己进入了睡眠状态。然后，在某个时间点上，由于某种未知的力量，线程被唤醒，一切继续进行。

我怀疑是其他中断造成的问题，但是在启用sched:,irq:,timer:*跟踪之后，我排除了这种可能性。我遇到了一些困难，在 ARM 内核中移植 syscalls:* 跟踪器。syscalls 跟踪器可以工作，但如果我还启用 sched:*，那么就会在 ring_buffer 代码内部出现各种错误。

在 fs/select.c 中插入一些自定义跟踪点后，我不得不不舒服地得出结论：在 sys_poll() 返回后，但尚未重新进入用户空间时，我的线程会进入睡眠状态。

以下是附带注释的跟踪结果：

 <my thread>-915   [001] ...1    17.589394: custom: do_poll:786 - calling do_pollfd
 <my thread>-915   [001] ...1    17.589399: custom: do_poll:794 - failed, no events
 <my thread>-915   [001] ...1    17.589402: custom: do_poll:823 - going to sleep, count = 0, timed_out = 0

.... // everything going OK, then the IRQ happens, which runs a tasklet:

 <random proc>-834 [000] d.h1    17.616541: irq_handler_entry: irq=17 name=hwblock handler=hw_block_process_irq
 <random proc>-834 [000] d.h1    17.616569: softirq_raise: vec=6 [action=TASKLET]
 <random proc>-834 [000] d.h1    17.616570: irq_handler_exit: irq=17 ret=handled
 <random proc>-834 [000] ..s2    17.616627: softirq_entry: vec=6 [action=TASKLET]

.... // the tasklet signals the wait queue of the poll, which wakes up my thread:

 <my thread>-915   [001] ...1    17.616827: custom: do_poll:826 - woke up, count = 0, timed_out = 0
 <my thread>-915   [001] ...1    17.616833: custom: do_poll:772 - start of loop
 <my thread>-915   [001] ...1    17.616840: custom: do_poll:786 - calling do_pollfd
 <my thread>-915   [001] ...1    17.616852: custom: do_poll:788 - success, event!
 <my thread>-915   [001] ...1    17.616859: custom: do_poll:810 - bailing, count = 1, timed_out = 0
 <my thread>-915   [001] ...1    17.616862: custom: do_sys_poll:880 - before free_wait()
 <my thread>-915   [001] ...1    17.616867: custom: do_sys_poll:882 - before __put_user()
 <my thread>-915   [001] ...1    17.616872: custom: sys_poll:940 - do_sys_poll - exit

.... // the tasklet exits, and my thread appears to be about to be

 <random proc>-834 [000] .Ns2    17.616922: softirq_exit: vec=6 [action=TASKLET]


.... // wait wait, why is my thread going back to sleep, and what was it doing for 75us?

 <my thread>-915   [001] d..3    17.616947: sched_stat_wait: comm=<another thread> pid=1165 delay=1010000 [ns]
 <my thread>-915   [001] ...2    17.616957: sched_switch: prev_comm=<my thread> prev_pid=915 prev_prio=0 prev_state=S ==> next_comm=<another thread> next_pid=1165 next_prio=120

.... // everything running on for 20ms as if nothing is wrong, then my thread suddenly gets woken up.
.... // nothing pid 947 is doing should have any effect on <my thread>

<random proc>-947  [000] d..4    17.636087: sched_wakeup: comm=<my thread> pid=915 prio=0 success=1 target_cpu=001
<random proc>-1208 [001] ...2    17.636212: sched_switch: prev_comm=<rancom proc> prev_pid=1208 prev_prio=120 prev_state=R ==> next_comm=<my thread> next_pid=915 next_prio=0
<my thread>-915    [001] ...1    17.636713: tracing_mark_write: poll() exit

My线程在某个地方变成了TASK_INTERRUPTIBLE，然后自愿地走入调度程序，然后......20ms后醒来，原因不明。

这种情况似乎至少在一定程度上与时间有关，各种尝试观察它往往使它更难以再现。

问题

1. 有什么想法是什么导致了这个问题？
2. 有没有简单的方法找出我的线程睡眠在哪里？
3. 有没有简单的方法找出我的线程为什么会醒来？
4. 我考虑过如何适应unwind_backtrace()生成一个我可以塞进每个trace_sched_switch()调用中的单个字符串，但那似乎有点令人生畏。还有什么其他类似的简单方法吗？
5. 有没有想法，为什么跟踪syscalls:*和sched:*会导致它在需要移动尾部的环形缓冲区代码中爆炸出未处理的页故障？看起来它在解除引用用户空间指针（基于数字相似性），但每次都是不同的。

我已经尝试并检查过的事情

1. 这不是运行时间过长的正常IRQ，或者与禁用中断有关。使用irq:*跟踪显示了这一点。可能是某种TrustZone NMI，但我有点怀疑。

2. 它不应该是任何RT限制/时间切片的产物，因为：

   a) sched_rt_runtime_us = 10000和sched_rt_period_us = 10000

   b) 线程具有相当低的工作周期（每秒小于30ms，在60-80个事件每秒）

3. 这可能不是来自用户空间的跟踪或写入/sys/kernel/debug/tracing/trace_marker的人工产物——即使从内核中禁用跟踪（甚至编译掉），它也会发生。此外，在trace.c和ring_buffer.c中相关的代码似乎大多是无锁的。

4. 除了优先级0之外没有其他东西，并且它没有被抢占，而是似乎自愿取消调度。

5. 我在syscall_trace()的顶部放置了一个panic()，以确保我没有在从sys_poll()退出时不小心掉入跟踪/审核路径之一。它没有触发，所以不是这个问题。

非常感谢您提前的帮助。

更新#1

我放弃寻找简单的方法，并实现了一个unwind_backtrace_to_str()函数，让我用回溯信息装饰各种跟踪点。在给trace_sched_switch()和trace_sched_wake()添加回溯后，我成功地隔离出了几个延迟的原因，其中两个主要是：

优先级倒置是由于在同一进程中执行fork()/mmap()/munmap()时，某些线程会占用mm->mmap_sem，因此在RT线程进行futex_wait()或tracing_mark_write()时无法使用该信号量。通过重构代码并在某些地方使用vfork()而不是fork()，可以大部分避免此问题。

• 未能运行计划任务，原因是在调用sched_wake()的CPU与需要运行任务的CPU不同。这似乎是一个更大的问题。我通过调度程序进行了跟踪，并发现在糟糕的情况下，wake_up_process()调用try_to_wake_up()，这最终调用ttwu_queue()，这就比较有趣了。

在ttwu_queue()内部，我们没有进入 'if'，因为cpus_share_cache()对于我们的任何核心始终返回true（听起来正确，共享L2缓存）。这意味着它只是为任务调用ttwu_do_activate()然后退出。ttwu_do_activate()似乎只将任务放在正确的运行队列上并将其标记为TASK_RUNNING，但没有任何SMP处理。

我在ttwu_do_wakeup()中的p->state = TASK_RUNNING;之后添加了以下内容：

#ifdef CONFIG_SMP
      if (task_cpu(p) != smp_processor_id())
          smp_send_reschedule(task_cpu(p));
#endif

该问题可以通过强制目标CPU运行调度器来解决。然而，我怀疑这不是它应该工作的方式，即使这是一个真正的错误，也可能有一个更精细的修复方法。我检查了最新的内核（3.14），core.c中的代码看起来基本相同。

为什么会这样？如果cpus_share_cache()返回true，为什么不调用ttwu_queue_remote()呢？即使它们共享缓存，那又怎样--我可以看出这对于迁移决策很重要，但唤醒是本地还是远程完成呢？也许我们的cpus_share_cache()应该返回false？这个函数似乎没有很好的文档记录（或者我没有找对地方）。

- Yuriy Romanenko

---

你是否有任何自定义设备驱动程序可能会干扰进程的调度结构？ - wallyk

Yuriy Romanenko，你当前的 uname -a 是什么？如果你想要进行RT（实时）任务，你测试过Linux内核的RT版本（https://www.kernel.org/pub/linux/kernel/projects/rt/3.4/）了吗？这可能会修复这个bug... - osgx

Answer 1

只是一次猜测，因为没有任何答案..您说系统是多核的。 您是否将用户线程的优先级分配给在中断发生的相同核心上运行的线程？中断是否仅在特定核心上发生？我怀疑一个情况，即用户线程在一个核心上运行，但中断发生在另一个核心上，并且无法立即恢复（还没有睡觉？）。可能会发生数据竞争，导致其进入休眠状态，例如在中断处理程序发布线程轮询的某些数据之前。因此，它被暂停直到下一个系统中断（例如计时器）。

因此，请尝试将中断和线程分配到同一个核心中，以便对它们进行序列化并避免潜在的数据竞争。

回应更新＃1

看起来我的关于内核代码中的数据竞争是正确的，因为在目标核心上引发IRQ可以修复该问题。 我想这不是因为过多地重新安排IRQ而不在内核代码中，因此增加了额外的调度开销，仅仅是为了很少的情况或者只是因为假设有共享缓存，可以更快地使用通常的同步完成。

而且有一些同步，看起来是正确的方向，但显然缺少了一些东西。我建议在不同的架构/版本上运行再现器，以了解它是否是普遍性的错误还是仅特定于您的平台/内核版本。我希望p->on_cpu的load/store没有遗漏任何围栏。

无论如何，回到您的具体问题，如果您不能或不想使用包含热修复的自定义内核构建，我的线程亲和力建议仍然有效。

此外，如果您不能将中断钉在一个特定的核心上，您可能需要在每个核心上运行这样的轮询线程（也明确地将其固定在其中），以确保至少有一个线程会在IRQ之后立即获得事件。当然，这导致了用户线程代码的额外同步负担。

- Anton

---

看起来你至少在这方面有一些头绪。请看我的编辑。 - Yuriy Romanenko

@YuriyRomanenko，谢谢，我没有太多要补充的（尽管已更新），仍然建议如果您不想黑掉内核，请尝试设置线程亲和性。 - Anton

我怀疑这不是一个围栏/屏障问题。该任务尚未处于on_cpu或on_rq状态。我见过的最病态的情况是，当CPU0在CPU1上对RT任务进行sched_wake时，CPU1处于空闲和WFI状态。然后什么也没发生。CPU1没有运行任务100ms，唯一的原因是某些HW IRQ唤醒了它，并且在出去的路上，它回到了调度程序并看到它有事情要做。因此，即使CPU处于空闲状态，也没有生成IPI。 - Yuriy Romanenko

@YuriyRomanenko，请澄清您当前想要什么，是修复内核还是绕过其行为？ - Anton

@Anton - 我们肯定可以修复内核。但我不知道我们是否能够进行像替换整个内核这样潜在破坏性的更改；在Linux/Android世界中，这种做法是否可行？ - Carl Norum

Answer 2

我们最终采用了以下解决方案：

• 在调度程序中添加smp_send_reschedule(task_cpu(p));，以允许跨CPU预防。我会跟进维护者，确认这是否是正确的解决方案。

• 为我们的平台实现get_user_pages_fast()，如果不需要锁定mmap_sem，则无需锁定。这消除了mmap/munmap和futex_wait之间的竞争。

• 在一些用户空间代码中，将vfork() + execve()替换为fork()是不必要的。这消除了mmap/munmap和调用生成其他进程的函数之间的竞争。

现在似乎一切都运行顺利。

感谢您的所有帮助。

- Yuriy Romanenko