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

描述

我正在研究一个在多核ARMv7a SoC上运行的嵌入式Linux系统(使用内核3.4和仿生,类似Android).我们有一个用户空间线程,它基本上处理来自内核的事件.事件是从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
        }
    }

通常我们会得到非常好的延迟(线程在IRQ发生的同一毫秒内完全往返于poll()),然而随机我们有几十毫秒的延迟会破坏一切.在遍历整个地方之后,我得出结论,延迟发生在IRQ触发之后和poll()系统调用返回之前,因为线程使自己处于睡眠状态.然后一段时间后被一些未知的力量唤醒,一切都继续.

我怀疑其他一些IRQ但是在启用了sched:,irq : , timer:*tracing我不得不排除它.我在移植系统调用时遇到了一些困难:*跟踪器到ARM内核.系统调用跟踪器工作,但如果我也启用sched:*我在ring_buffer代码中得到各种各样的恐慌.

在sys_poll()中插入一些自定义跟踪点之后,我得到了一个令人不舒服的结论,即我的线程在sys_poll()返回之后但在它重新出现在用户空间之前就已经睡着了.

这是带有我在fs/select.c中的自定义跟踪点的带注释的跟踪:

 -915   [001] ...1    17.589394: custom: do_poll:786 - calling do_pollfd
 -915   [001] ...1    17.589399: custom: do_poll:794 - failed, no events
 -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:

 -834 [000] d.h1    17.616541: irq_handler_entry: irq=17 name=hwblock handler=hw_block_process_irq
 -834 [000] d.h1    17.616569: softirq_raise: vec=6 [action=TASKLET]
 -834 [000] d.h1    17.616570: irq_handler_exit: irq=17 ret=handled
 -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:

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

 -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?

 -915   [001] d..3    17.616947: sched_stat_wait: comm= pid=1165 delay=1010000 [ns]
 -915   [001] ...2    17.616957: sched_switch: prev_comm= prev_pid=915 prev_prio=0 prev_state=S ==> next_comm= 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 

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

所以我的地方线程被越来越TASK_INTERRUPTIBLE然后自愿走进调度,然后......醒来的显然没有理由20ms的更新版本.

这种情况的发生似乎至少在一定程度上依赖于时间,并且观察它的各种尝试通常使得再现更难.

问题

是什么原因引起了这个？

有关找出我的线程在哪里睡着的简单方法的任何建议？

有关简单方法找出我的线程唤醒原因的任何建议吗？

我已经考虑过以某种方式适应unwind_backtrace()生成一个字符串,我可以填入每个trace_sched_switch()调用,但这似乎有点令人生畏.沿着同样的路线更简单吗？

任何想法为什么跟踪系统调用:*和sched:*会使它在环形缓冲区代码中的未处理的页面错误中爆炸,它需要移动尾部？它似乎是取消引用用户空间指针(基于数字相似性),但每次都是不同的.

我已经尝试过并检查过的东西

这不是一个运行时间过长的正常IRQ或者具有禁用中断的东西.跟踪irq:*表明.它可能是某种TrustZone NMI但不知何故我对此表示怀疑.

它不应该是任何类型的RT限制/时间限制,因为:

a)sched_rt_runtime_us = 10000和sched_rt_period_us = 10000

b)线程占空比相当低(<30ms/s,每秒60-80次事件)

它可能不是/sys/kernel/debug/tracing/trace_marker从用户空间进行跟踪或写入的工件- 它在没有该宏的情况下发生并且禁用跟踪(甚至从内核编译).此外,与trace.c和ring_buffer.c中的代码相关的代码似乎主要是无锁的.

没有其他优先级为0,并且它没有被抢占,而是似乎心甘情愿地取消了自己的计划.

我在顶部放了一个恐慌(),syscall_trace()以确保我在出路时不会意外地落入其中一条跟踪/审核路径sys_poll().它没有发射,所以不是这样.

非常感谢你提前

更新#1

我放弃了寻找简单的东西并实现了一个unwind_backtrace_to_str()功能,让我可以使用回溯信息来检测各种跟踪点.在向trace_sched_switch()和trace_sched_wake()添加回溯之后,我设法隔离了几个延迟的原因,主要的两个是:

由于mm-> mmap_sem的优先级倒置是由同一进程中的某个其他线程执行fork()/ mmap()/ munmap()因此在RT线程期间futex_wait()或tracing_mark_write()为RT线程不可用.通过重构一些代码并在某些地方使用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处理.

我加入后,下面p->state = TASK_RUNNING;的ttwu_do_wakeup()

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

它通过强制目标CPU运行调度程序来解决问题.但是,我怀疑这不是它应该如何工作,即使这是一个真正的错误,那么可能还有一个更精确的修复.我检查了最新的内核(3.14),core.c中的代码看起来几乎一样.

任何想法为什么会这样？ttwu_queue_remote()如果cpus_share_cache()返回true,为什么不调用？那么如果他们共享缓存会怎么样 - 我可以看到这与迁移决策有什么关系,但唤醒是在本地还是远程完成？也许我们 cpus_share_cache()应该归还假？该功能似乎没有很好地记录(或者我没有找到正确的位置)