kill命令正常执行,但进程迟迟没有退出。非必现场景,在批量回收资源时比较容易出现,平时开发测试时没有遇到。从场景上看出现的概率并不高,可能是在某种极端条件下才能触发,由于第一次收到报告后没有保留现场,先到官方JIRA平台上去搜相关的BUG,无果,又盲目的尝试了几个场景后只能先Hold住,等待下次出现。
很幸运,第二天BUG再次出现,僵尸进程?死循环?死锁?没有收到Kill信号?无数想法蹦出来,迅速登陆机器,查看现场,先从最简单的可能性开始开始排查。
top
第一套组合拳,排除了僵尸进程可能性,并且TOP显示CPU使用率为0并不高;strace继续跟进查看,也没有发现有系统调用,最后在补一个pstack打印堆栈信息,全部线程都在wait。BUG的排查方向大致确定:线程间资源同步的问题(当然也不能排除是其他的可能性)。
详细分析pstack内容,从堆栈信息中看一个长相特别的(其他大部分的线程堆栈都是雷同的):
97 void ReplicationCoordinatorExternalStateImpl::shutdown() {
98 boost::lock_guard<boost::mutex> lk(_threadMutex);
99 if (_startedThreads) {
100 log() << "Stopping replication applier threads";
101 _syncSourceFeedback.shutdown();
102 _syncSourceFeedbackThread->join();
103 _applierThread->join();
104 BackgroundSync* bgsync = BackgroundSync::get();
106 _producerThread->join();
107 }
108 }
这么多的join,到底是哪个呢。上GDB,我们来看看Thread 46到底在等谁。先加载symbol-file,失败,加载后堆栈变得更乱了,换disassemble
命令,显示汇编信息:
查看0x0000000000c8eeb7
地址的上下文,通过前后指令的函数符号名确定了目前代码是在_applierThread->join()
,这里可以思考下是否还有的其他方法获得代码行。
_applierThread
同样也是个线程,如果shutdown在等它,那它又在等谁呢,回头继续查pstack输出,找到相关的堆栈:
Thread 34 (Thread 0x2b5f0a6d8700 (LWP 1355)):
#1 0x0000000000c2687b in mongo::repl::BackgroundSync::waitUntilPaused() ()
#2 0x0000000000cd192e in mongo::repl::SyncTail::tryPopAndWaitForMore(mongo::OperationContext*, mongo::repl::SyncTail::OpQueue*, mongo::repl::ReplicationCoordinator*) ()
#3 0x0000000000cd2823 in mongo::repl::SyncTail::oplogApplication() ()
#4 0x0000000000ccaaaf in mongo::repl::runSyncThread() ()
#5 0x0000000000feb384 in ?? ()
#6 0x0000003018007851 in start_thread () from /lib64/libpthread.so.0
#7 0x000000300a4e767d in clone () from /lib64/libc.so.6
注意这里与shutdown的等待是不同的,shutdown是在等待线程退出,而这里是在等待某个条件变量,再次上GDB,查看Thread 34 & backtrace 1, info locals
:
469 void BackgroundSync::waitUntilPaused() {
470 boost::unique_lock<boost::mutex> lock(_mutex);
472 _pausedCondition.wait(lock);
473 }
474 }
_pause
变量一直都是0,所以会hang在这里。继续查看代码,跟踪_pausedCondition
的调用,有两个函数会去唤醒,一个是stop,另一个是shutdown,但shutdown的调用应该在线程退后调用,以便释放资源。
同时,再次回过来在pstack中查看BackgroundSync
的堆栈信息,想看看到底卡在了哪里。结果找不到BackgroundSync
线程,问题更清晰了,所有条件变量的唤醒,都是在该线程中完成的,如果BackgroundSync
已经不存在了,一定会hang住。
再反复阅读代码,BackgroundSync
在判断到inShutdown()
时会自动结束生命周期,但结束后并没有更改_pause
状态。
解决办法是线程最后退出前执行stop函数,修改_pause
状态,(shutdown会提前释放资源),查看官方最最新代码,确认有同样的修改,反向追踪提交,找到相关,抱怨JIRA的搜索弱爆了。
1908 case kActionWinElection: {
1909 boost::unique_lock<boost::mutex> lk(_mutex);
1910 _electionId = OID::gen();
1911 _topCoord->processWinElection(_electionId, getNextGlobalOptime());
1912 _isWaitingForDrainToComplete = true;
1913 const PostMemberStateUpdateAction nextAction =
1914 _updateMemberStateFromTopologyCoordinator_inlock();
1915 invariant(nextAction != kActionWinElection);
1916 lk.unlock();
1917 _performPostMemberStateUpdateAction(nextAction);
1918 break;
也就是说刚刚赢得了选举后会产生_isWaitingForDrainToComplete == true
状态,恰巧这个时间窗口内进程接受到退出信号。复现的办法就是在 的后面加上sleep,以此来延长时间窗口,当然也可以通过GDB BLOCK的方式来复现。