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_7CommandERKSsRNS_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_7CommandERKSsRNS_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均已修复。
本文转自UltraSQL51CTO博客,原文链接:http://blog.51cto.com/ultrasql/1620672 ,如需转载请自行联系原作者