问题终于处理清楚了,如此坑爹的问题,陆陆续续的搞了有近月的时间,现在有时间写一个过程与总结。

问题现象:进程H需要每隔10s发消息给M(类似watchdog的功能),否则就会有功能异常的告警,业务发现了异常的告警,恰好OS监控日志中记录下了进程H当时是D状态,持续了约20s就恢复过来了,然后就没有然后,啥日志也没有。对于这个问题,各位老大进行亲切友好的交谈,双方达成一致意见:放到攻关团队中搞,OS重点投入。

拿到问题的时候,一堆日志里面翻来翻去,除了知道进程H当时D状态(而且进程H拆出了大约70~120个线程),就没有其他有效信息。问题也不重现。本着“没有搞不定的问题,只有不重现的问题”的原则,构造条件准备重现问题

在增大业务量做压力重现的时候,神奇的事情发生了,H主线程没有发生D状态,另外一个K进程则进入了D状态,最关键的是杀掉H进程后,K进程就恢复正常了,否则就会一直D状态长时间不恢复。看来H进程和K进程是有关系的,那就先入手必现的问题,把K进程的问题搞定。 由于K D状态是必现问题,就可以通过

将进程的调用栈打印出来,根据栈的信息看到看到K进程D状态的过程:(其实proc的栈缺的太多,很多中间过程全靠脑补) K进程调用了mlock用来锁定内存(使其不置换到SWAP上,降低效率),mlock干活之前使用lru_add_drain_all回刷pagevec(pagevec是什么),lru_add_drain_all对每个CPU下发work函数lru_add_drain_per_cpu。

flush_work中wait_for_completion使用

K进程D状态住的原因就是kworker上的lru_add_drain_per_cpu函数一直没有完成,目前看就是任务队列中的调度有问题。 然后将所有的CPU的调用栈搞出来,发现虽然K进程对每个CPU下发了work任务,但只有一个核的CPU调用栈是如上描述,其他CPU都是正常的。排查所有的进程发现,同一个核上还有一个H线程在跑,后来发现H进程都是实时线程,采用FIFO的调度模式(具体信息请先了解实时进程),而且它的实时优先级大于kworker优先级,在H线程承接大业务时,一直抢占CPU不释放,导致kworker一直得不到调度,直接导致K进程D状态,一直挂死。手工写两个程序模拟了H与K进程,问题确实如此。

但是H进程D状态的问题也没有解决,只能靠重现了,终于,问题重现了,在H进程D状态的20s,将它所有线程的调用栈打印出来,可以先到 /proc/`pidof H`/task下,查到所有的子线程。发现H有7,8个线程处于D状态,且它的D状态函数流程是: do_page_fault下调用down_read(&mm->mmap_sem)加锁,down_read调用__down_read,其在内联汇编中调用call_rwsem_down_read_failed,还是汇编:

实际上proc调用栈只到call_rwsem_down_read_failed,后面就没了,只好考脑补推测代码。 rwsem_down_read_failed调用rwsem_down_failed_common

rwsem_down_failed_common中存在将当前进程置成D状态的行为,而且在进程解状态前有循环,嫌疑就是它了。

rwsem_down_failed_common是内核读写锁的一部分,(具体细节请自行了解)。

在缺页中断中使用up_read获取线性区的读写信号量的读锁,发现rw_semaphore.count值为-1(有写锁),则获取读锁失败,(下划线并不完全正确,后面解释)进入rwsem_down_failed_common,把当前进程加入rwsem_waiter中,添加到队列中,进入死循环,等待waiter.task为空,即当前进程不在等待列表中,已经获取了读锁。

排查了所有H线程,问题点没有线程占用写锁,然后写工具获取H进程线性区读写信号量的等待队列内容,将整个过程录下来,发现如下:

khugepaged获取写锁--->H多个线程因为缺页中断获取读锁,被阻塞--->khugepaged释放写锁,H多线程集体获取读锁---->khugepaged再次申请写锁,被阻塞--->H多线程集体获取读锁,除一个外(记作H1)其他都释放--->其他H多线程申请读锁,排队在khugepaged后面,等待占有读锁的H线程释放,等待超过20s后H释放--->一切恢复正常。

问题就出在H1线程占有读锁后没释放,也是由缺页中断触发,翻看up_read和down_read中间没有耗时操作,而且栈的挂死点在up_read内,再次写工具将该H线程的详细的内核调用栈导出来,对应内核反汇编代码,比较内存地址发现,代码挂死在schedule()行,也就是H1线程没有调用回来。

翻看运行在同一个CPU核上进程有一个H2,而且H1和H2都是被cpu绑定到5核上,H2处理主要业务,H1辅助,H2实时优先级高,H1实时优先级低,当H2压力大占用100% CPU时,H1就得不到调度了。OK,问题原因基本清楚了。

重现梳理一下各个进程过程。

高业务压力下,H2一直占用CPU,是R状态,H1得不到调度,是S状态。首先是khugepaged获取写锁,同时包含H2的多个H线程因缺页中断申请读锁,H2处于D状态被schedule让出CPU,H1也恰好缺页中断,获得CPU后申请读锁,排在H2后面,也是D状态。khugepaged释放写锁后,khugepaged先将所有等待读锁的进程拉入读写锁,并将其置成TASK_WAKING状态(参考__rwsem_do_wake函数)。H2先调度回来获取了读锁并完全占用了5核CPU,本来读锁支持并发,但H1此时没有了CPU可供使用,没有调度,一直在schedule打转,虽然进程没有调度,但H1已经被khugepaged拉到读写锁,占用了读锁,一直不释放,khugepaged申请写锁也不能完成,后续更多H缺页中断申请读锁也被阻塞住,D状态达到20s。至于后续能恢复,是因为H2再次因为缺页要申请读锁,排队到队列,进入D状态,schedule让出CPU,H1才能再次得到CPU,完成工作后释放读锁。

整个过程中,进程来线程往,川流不息,各种条件相互叠加,缺一不可,造成一个类似珍珑棋局般死锁。

亚马逊的蝴蝶扇一下翅膀,德州则起了一场风暴,编程之美,确是如此。


读写信号量与实时进程阻塞挂死问题来自于OenHan

链接为:http://oenhan.com/rwsem-realtime-task-hung

3 对 “读写信号量与实时进程阻塞挂死问题”的想法;

ss进行回复 取消回复