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(::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(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的返回值和操作系统、编译器有关。

经测试，Windows10上用VS2015时vsnsprintf能返回期望结果——被截断前的信息的长度。

个人觉得这段代码非常值得学习。首先是考虑了内存分配的情况。通常看到的日志实现中，要么是在栈中设定一个定长缓冲区，然后设定一个日志最大长度，以此来避免内存分配；要么是直接分配一大块内存来放日志字符串。这里作者使用了两级“内存分配”，首先在栈中分配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","灿哥哥的博客");