MongoDB 4.0 启动失败问题定位

深碍√TFBOYSˉ_ 2022-12-25 15:57 363阅读 0赞

## 分析 ##

mongod是启动MongoDB的主程序，该程序通过命令行参数或者配置文件进行启动。

mongod会在MongoDB异常关闭后（例如OOM Killer前置关闭Mongo进程），执行恢复过程，无需采用repair参数启动，因此正常情况下mongo启动会成功的，除非有错误。错误通过错误日志可以排除。

本篇的问题现象是，mongo被OOM kill之后，多次重新启动后，mongod主动关闭，日志大概如下：

[initandlisten] Assertion failure kill(serverGlobalParams.leaderProc.toNative(), 12) == 0 src/mongo/db/initialize_server_global_state.cpp 103
     ----- BEGIN BACKTRACE -----
    {"backtrace":[{"b":"55D7C7719000","o":"24183E1","s":"_ZN5mongo15printStackTraceERSo"},
    ...
     [ShardServerCatalogCacheLoader-0] Marking host m4.mongo.cnbd:27003 as failed :: caused by :: ShutdownInProgress: connection pool is in shutdown

或者

[signalProcessingThread] shutting down replication subsystems
     ...
      [signalProcessingThread] got signal 1 (Hangup), will terminate after current cmd ends
       [signalProcessingThread] shutting down replication subsystems

此环境我在恢复一个一主一从的DB分片库时，出现的错误日志，日志提示恢复数据成功后，MongoDB主动关闭，导致恢复失败，尝试过程启动方式后无果，经过分析MongoDB的启动过程，并亲自写代码做实验，发现MongoDB的启动的一个小漏洞。  
当提示“will terminate after current cmd ends”表示系统在执行完当前命令后就会停止运行，如果是在启动的恢复过程，那么在恢复执行完成后停止。（mongo的oplog日志恢复后，如果主从状态没有达成一致是不会固化oplog的，这意味着下次重启需要重新恢复，如果oplog很大，那么恢复时间就很长）

## 查找 ##

经过检索，发现官方有人提出此问题，现象和我一致，具体问题报告如下：[参考链接][Link 1]  
![Mongo SERVER-27742][]  
从上图可以看出该问题已经关闭，开发团队的答复是；  
We think this is currently functioning as we would expect.  
大意就是：我们认为当前该功能是如我们所期望的那样。

那……我的文件无解吗？特意查看了mongod的启动过程，如下：  
首先mongo会在启动的时候，派生子进程和孙进程，这个逻辑是为MongoDB主程序运行在后台做守护进程做准备，具体原因可以参考[这里][Link 2]，这都没有问题。可是，如果启动mongo没有结束，那么主进程就不会结束（启动成功会提示fork successfully）。启动过程中，会出现父进程/子进程/孙进程三代同堂的场景（通过ps -ef | grep mongod可以查看）。此时如果是通过ssh连接，如果没有采用nohup启动，那么等mongo加载完毕后，MongoDB会自动退出（源码后面论述）。这里注意，把mongod作为后台启动后，如果终端异常退出，进程依然会关闭，分析参考[这里][Link 3]。

> 小提示：启动mongo服务请采用nohup mongod -f … &启动

## 不完善的处理 ##

经过分析，我任务问题出在没有采用nohup导致启动失败，可是事情远没有这么简单，我自信的任务我用nohup启动后一定可以启动，可是事实再一次打脸（我的oplog日志50+GB，恢复需要4-5天时间）。  
我怀疑是nohup有什么问题，如是采用screen方式启动……结果运行一天之后，发现恢复没有结束，进程只留下孙进程，如此经过几天之后，一定会自动关闭的。  
上一段引起此问题引起伤心的代码：r4.0.7

void signalForkSuccess() {
        if (serverGlobalParams.doFork) {
            // killing leader will propagate to parent
            verify(kill(serverGlobalParams.leaderProc.toNative(), SIGUSR2) == 0);
        }
    }

上述代码就是在mongdb恢复完成后，会执行fork成功的函数，该函数有一个verify验证kill发送SIGUSR2信号是否成功，该信号是发给父进程的，如果父进程不在，那么该验证一定会失败，导致程序退出。该代码也是官方任务是合理的，是他们期望的工作方式。

期望的工作方式，为什么有问题呢，恢复经过半个月的尝试依旧失败，业务一致挂起！伤心！（对不起我的客户）

作为程序员，我知道，问题一定在某个地方。

我怀疑nohup时，我通过screen方式启动mongod后（screen的优点请看[这里][Link 4]），第二天发现屏幕上有一个：“signal 1”的消息，我知道了……一切后果都是有原因的。

大家知道，SIGUSR1是Mongo的日志回旋功能信号，该功能可以让Mongo日志截断，避免日志文件过大，而无法清理。而这里的信号1就是SIGUSR1.

## 关键问题 ##

原来问题出在这儿！因为我之前为了清理日志方便，写了定时任务，每日给所有mongod进程发送SIGUSR1信号进行日志回旋操作。可是，如果在恢复的时候，此时三代同堂，那么父进程和子进程也会接收到该型号（我的脚本是遍历所有mongod进程的），那么如果没有设置信号处理器的程序就会采用默认动作终止程序。这三个进程中，只有孙进程处理了SIGUSR1信号，导致留下未完成恢复使命的孙进程，等他恢复完后，无法发送关闭祖父的信号时，他会默默的停止服务……

所以……如果需要恢复数据库，且需要耗费较长时间，那么请一定要**关闭日志清理定时任务**！切记！

那么Mongod的正确启动姿势为：

nohup mongod -f /xx/mongod.conf > mongo-boot.log 2>&1 &

[Link 1]: https://jira.mongodb.org/browse/SERVER-27742
[Mongo SERVER-27742]: /images/20221120/a557c9bd421949c79d1a37745d00288c.png
[Link 2]: https://blog.csdn.net/linkedin_35878439/article/details/81288889
[Link 3]: https://www.cnblogs.com/bohaoist/p/4965103.html
[Link 4]: https://www.linuxprobe.com/screen-remote-use.html