LevelDB源码分析之十：LOG文件

首先要区分LOG文件和.log文件。

LOG文件：用来记录数据库打印的运行日志信息，方便bug的查找。

.log文件：在LevelDB中的主要作用是系统故障恢复时，能够保证不会丢失数据。因为在将记录写入内存的Memtable之前，会先写入.log文件，这样即使系统发生故障，Memtable中的数据没有来得及Dump到磁盘的SSTable文件，LevelDB也可以根据.log文件恢复内存的Memtable数据结构内容，不会造成系统丢失数据。

Env.h中定义了操作LOG文件的虚基类Logger，只提供了一个对外的接口Logv。Logger的Windows版本实现是WinLogger。

// win_logger.h
class WinLogger : public Logger {
private:
FILE* file_;
public:
explicit WinLogger(FILE* f) : file_(f) { assert(file_); }
virtual ~WinLogger() {
fclose(file_);
}
virtual void Logv(const char* format, va_list ap);
};

// win_logger.cc
void WinLogger::Logv(const char* format, va_list ap) {
// 获取当前线程ID
const uint64_t thread_id = static_cast<uint64_t>(::GetCurrentThreadId());

// We try twice: the first time with a fixed-size stack allocated buffer,
// and the second time with a much larger dynamically allocated buffer.
// 尝试两次内存分配：第一次分配固定大小的栈内存,如果不够，第二次分配更大的堆内存
char buffer[500];

for (int iter = 0; iter < 2; iter++) {
char* base;
int bufsize;
if (iter == 0) {
bufsize = sizeof(buffer);
base = buffer;
} else {
bufsize = 30000;
base = new char[bufsize];
}

char* p = base;
char* limit = base + bufsize;

SYSTEMTIME st;

// GetSystemTime returns UTC time, we want local time!
::GetLocalTime(&st);

p += _snprintf_s(p, limit - p, _TRUNCATE,
"%04d/%02d/%02d-%02d:%02d:%02d.%03d %llx ",
st.wYear,
st.wMonth,
st.wDay,
st.wHour,
st.wMinute,
st.wSecond,
st.wMilliseconds,
static_cast<long long unsigned int>(thread_id));

// Print the message
if (p < limit) {
va_list backup_ap = ap;
// limit-p是p可接受的最大字符数
p += vsnprintf(p, limit - p, format, backup_ap);
va_end(backup_ap);
}

// Truncate to available space if necessary
// 如果第一次分的栈内存不够，会第二次分配更大的堆内存。
// 如果第二次分的内存还不够，只能对存放内容做截断处理了。
// 为什么p==limit也算内存不够呢？因为最后要存放换行符，
// 所以有效的内容最大长度只能是limit-p-1。
if (p >= limit) {
if (iter == 0) {
continue; // Try again with larger buffer
} else {
p = limit - 1;
}
}

// Add newline if necessary
// 如果p==base或者有效内容的最后一个字符不是换行符
// 则将换行符添加到最后
if (p == base || p[-1] != '\n') {
*p++ = '\n';
}

assert(p <= limit);
fwrite(base, 1, p - base, file_);
// fwrite只是将写入内容放入缓存中，真正输出到文件是通过fflush实现的。
fflush(file_);
// 如果分配了堆内存，需要手动释放。
if (base != buffer) {
delete[] base;
}
break;
}
}

我用的是Windows版LevelDB，上面这段代码在Windows 7上用VS2013调试时是有bug的。当要打印的日志信息长度超过30000时，vsnsprintf会截断信息，但是vsnsprintf并不会返回被截断前的信息的长度，而是返回-1，这样一来，那一行日志信息只会打印出日期、时间和线程号，尽管一行日志超过30000字节的概率非常小。经查证，vsnsprintf的返回值和操作系统、编译器有关。详见：https://bytes.com/topic/c/answers/590845-snprintf-return-value

经测试，Windows10上用VS2015时vsnsprintf能返回期望结果——被截断前的信息的长度。详见：http://blog.csdn.net/caoshangpa/article/details/78938853

个人觉得这段代码非常值得学习。首先是考虑了内存分配的情况。通常看到的日志实现中，要么是在栈中设定一个定长缓冲区，然后设定一个日志最大长度，以此来避免内存分配；要么是直接分配一大块内存来放日志字符串。这里作者使用了两级“内存分配”，首先在栈中分配500个字节的缓冲区，这样长度小于500字节的日志就可以避免掉new的开销。如果发现放不下，再去new一个大块内存。当然如果单行日志太大，超过了30000字节，那么就直接做截断了。其次就是内存的防越界处理。

不过这里有个疑问，为何添加换行符的时候要判断p==base，知道的同学请指点下。

最后在Env.h中封装了一个全局的方法Log，方便调用接口Logv，如下所示。

void Log(Logger* info_log, const char* format, ...) {
if (info_log != NULL) {
va_list ap;
va_start(ap, format);
info_log->Logv(format, ap);
va_end(ap);
}
}

调用方法：Log(result.info_log, "Ignoring error %s","灿哥哥的博客");