MongoDB日志切换（Rotate Log Files）方法及注意事项

MongoDB日志切换（Rotate Log Files）方法及注意事项

 

转载自：http://duoyun.org/topic/512047a5cd0cc40a0a04c381

 

MongoDB日志默认不会切换，生产系统尤其是压力大的系统，日志滚动速度非常快，我们上线系统最大的一个mongod进程的log每天增长5G多。目前采取策略是每天切换一次，保存一周的日志。

目前采取的方法：

· SIGUSR1 方法

killall -SIGUSR1 mongod  
每天0点定时执行来达切换日志。

大部分情况下并无问题，但近期集中出现了两台服务器日志切换时出现问题，0点到0点20分左右，日志是空的。mongod 或者config报警，进程重启（自动），该bug至少要到2.5.x才修复。MongoDB的稳定性目前确实不尽人意。

 

· 采取mongo shell logRotate 来避免该bug

use admin  
db.runCommand( { logRotate : 1 } )    
此方法需要在mongos,mongod,config server运行，不能一次性切换所有日志。

 

logRotate命令也有‘bug’，这两天出现了两次（版本2.2.2）：

Sat May 4 00:01:02 [conn96028478] ERROR: Failed to rename /export/data/mongodb/log/mongod.log to /export/data/mongodb/log/mongod.log.2013-05-03T16-01-02 Fatal Assertion 16175

0xaffd31 0xac5323 0x70f4f1 0x6e8d71 0x6ea5e2 0x6eb59c 0x832c68 0x8363b0 0x7b072d 0x7b3a53 0x5703f2 0xaedfc1 0x32ad2077f1 0x32acee570d

/export/servers/mongodb/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xaffd31]

/export/servers/mongodb/bin/mongod(_ZN5mongo13fassertFailedEi+0xa3) [0xac5323]

/export/servers/mongodb/bin/mongod() [0x70f4f1]

/export/servers/mongodb/bin/mongod(_ZN5mongo12_execCommandEPNS_7CommandERK***NS_7BSONObjEiRNS_14BSONObjBuilderEb+0x51) [0x6e8d71]

/export/servers/mongodb/bin/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0xd52) [0x6ea5e2]

/export/servers/mongodb/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x2ac) [0x6eb59c]

/export/servers/mongodb/bin/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x38) [0x832c68]

/export/servers/mongodb/bin/mongod(_ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_+0xc10) [0x8363b0]

/export/servers/mongodb/bin/mongod() [0x7b072d]

/export/servers/mongodb/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x3a3) [0x7b3a53]

/export/servers/mongodb/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x82) [0x5703f2]

/export/servers/mongodb/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x411) [0xaedfc1]

/lib64/libpthread.so.0() [0x32ad2077f1]

/lib64/libc.so.6(clone+0x6d) [0x32acee570d]

Sat May 4 00:01:02 [conn96028478]

***aborting after fassert() failure

Sat May 4 00:01:02 Got signal: 6 (Aborted).

Sat May 4 00:01:02 Backtrace:

0xaffd31 0x558bb9 0x32ace32900 0x32ace32885 0x32ace34065 0xac535e 0x70f4f1 0x6e8d71 0x6ea5e2 0x6eb59c 0x832c68 0x8363b0 0x7b072d 0x7b3a53 0x5703f2 0xaedfc1 0x32ad2077f1 0x32acee570d

/export/servers/mongodb/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xaffd31]

/export/servers/mongodb/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x558bb9]

/lib64/libc.so.6() [0x32ace32900]

/lib64/libc.so.6(gsignal+0x35) [0x32ace32885]

/lib64/libc.so.6(abort+0x175) [0x32ace34065]

/export/servers/mongodb/bin/mongod(_ZN5mongo13fassertFailedEi+0xde) [0xac535e]

/export/servers/mongodb/bin/mongod() [0x70f4f1]

/export/servers/mongodb/bin/mongod(_ZN5mongo12_execCommandEPNS_7CommandERK***NS_7BSONObjEiRNS_14BSONObjBuilderEb+0x51) [0x6e8d71]

/export/servers/mongodb/bin/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0xd52) [0x6ea5e2]

/export/servers/mongodb/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x2ac) [0x6eb59c]

/export/servers/mongodb/bin/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x38) [0x832c68]

/export/servers/mongodb/bin/mongod(_ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_+0xc10) [0x8363b0]

/export/servers/mongodb/bin/mongod() [0x7b072d]

/export/servers/mongodb/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x3a3) [0x7b3a53]

/export/servers/mongodb/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x82) [0x5703f2]

/export/servers/mongodb/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x411) [0xaedfc1]

/lib64/libpthread.so.0() [0x32ad2077f1]

/lib64/libc.so.6(clone+0x6d) [0x32acee570d]

对应源码：

class LogRotateCmd : public Command {

public:

LogRotateCmd() : Command( "logRotate" ) {}

virtual LockType locktype() const { return NONE; }

virtual bool slaveOk() const { return true; }

virtual bool adminOnly() const { return true; }

virtual bool run(const string& ns, BSONObj& cmdObj, int, string& errmsg, BSONObjBuilder& result, bool fromRepl) {

fassert(16175, rotateLogs());

return 1;

}

} logRotateCmd;

 

rotateLogs()返回结果不对。

 

bool rotateLogs() {

return loggingManager.rotate();

}

rotateLogs()->rotate()

bool rotate() {

if ( ! _enabled ) {

cout << "LoggingManager not enabled" << endl;

return true;

}

if ( _file ) {

#ifdef POSIX_FADV_DONTNEED

posix_fadvise(fileno(_file), 0, 0, POSIX_FADV_DONTNEED);

#endif

// Rename the (open) existing log file to a timestamped name

stringstream ss;

ss << _path << "." << terseCurrentTime( false );

string s = ss.str();

if (0 != rename(_path.c_str(), s.c_str())) {

error() << "Failed to rename " << _path << " to " << s;

return false;

}

}

...

return true;

}

 

显然是rename函数运行出来问题。rename应该是boost::filesystem::rename函数，而filesystem/v3 有个bug ，rename文件时如果存在相同的目标文件名，会抛异常：  
boost::filesystem::rename throw exception when target file exists, but documentation tell us that it must be replaced    
https://svn.boost.org/trac/boost/ticket/2866    
MongoDB 2.2.2恰恰就是用的该版本。

那么mongod down的原因只能是还有别的进程在切日志，要不没法解释，这就的查查有没有别的机器连上了切日志。结果发现该机器mongo用户下有个相同的crontab 任务，而正常情况下都是用root用户的。自此罪魁祸首找到了！再深的bug都有个简单的源头！

 

另外：logRotate相关bug在2.2.5、2.4.3版本解决，详见SERVER-4739。

 

日志切换相关两个断言：  
16175 is for a failure of the 'logRotate' command (e.g. 'db.adminCommand("logRotate")').    
16176 is for a failure when SIGUSR1 has been received (not available on Windows).

 

· 使用syslog管理日志

2.2版本以后可采用--syslog选项，将日志由syslog管理。用syslog特性来切换日志。

修改/etc/rsyslog.conf    
.info;mail.none;authpriv.none;cron.none;user.none /var/log/messages    
user. /export/data/log/mongosyslog.log

 

修改/etc/logrotate.conf ，添加：  
/export/data/log/mongosyslog.log {    
missingok    
daily    
rotate 7    
postrotate    
/usr/bin/kill -HUP rsyslogd    
endscript    
}

 

设置了每天切换一次，手动切换方法logrotate -f /etc/logrotate.conf

more:    
https://groups.google.com/forum/?fromgroups=#!topic/mongodb-user/7buu-XYvSjs    
https://jira.mongodb.org/browse/SERVER-4739    
https://jira.mongodb.org/browse/SERVER-3339    
http://docs.mongodb.org/manual/tutorial/rotate-log-files/#rotate-log-files

 

更新ERROR:    
Failed to rename /export/data/mongodb/log/mongod.log to /export/data/mongodb/log/mongod.log.2013-05-03T16-01-02 Fatal Assertion 16175部分

 

日志切换另一个bug https://jira.mongodb.org/browse/SERVER-9578    
目前2.2.5,2.4.4均已修复。