Clean up posix_logger.h.

General cleanup principles:
* Use override when applicable.
* Use const on class members where possible.
* Renames where clarity can be improved.
* Qualify standard library names with std:: when possible, to
  distinguish from POSIX names.
* Qualify POSIX names with the global namespace (::) when possible, to
  distinguish from standard library names.

This also revamps the logic for putting together a message into the
in-memory buffer before that is passed to fwrite(). While correct in
practice, the current implementation advances a char pointer past the
size of its buffer, which is technically undefined behavior.

-------------
Created by MOE: https://github.com/google/moe
MOE_MIGRATED_REVID=211472570

1 files changed, 94 insertions, 64 deletions

diff --git a/util/posix_logger.h b/util/posix_logger.h
index 1909e61..a01a4fe 100644
--- a/util/posix_logger.h
+++ b/util/posix_logger.h
@@ -8,89 +8,119 @@
 #ifndef STORAGE_LEVELDB_UTIL_POSIX_LOGGER_H_
 #define STORAGE_LEVELDB_UTIL_POSIX_LOGGER_H_
 
-#include <algorithm>
-#include <stdio.h>
 #include <sys/time.h>
-#include <time.h>
+
+#include <cassert>
+#include <cinttypes>
+#include <cstdarg>
+#include <cstdio>
+#include <ctime>
+
 #include "leveldb/env.h"
 
 namespace leveldb {
 
-class PosixLogger : public Logger {
- private:
-  FILE* file_;
-  uint64_t (*gettid_)();  // Return the thread id for the current thread
+class PosixLogger final : public Logger {
  public:
-  PosixLogger(FILE* f, uint64_t (*gettid)()) : file_(f), gettid_(gettid) { }
-  virtual ~PosixLogger() {
-    fclose(file_);
+  PosixLogger(FILE* fp, uint64_t (*gettid)()) : fp_(fp), gettid_(gettid) {
+    assert(fp != nullptr);
+  }
+
+  ~PosixLogger() override {
+    std::fclose(fp_);
   }
-  virtual void Logv(const char* format, va_list ap) {
+
+  void Logv(const char* format, va_list arguments) override {
+    // Record the time as close to the Logv() call as possible.
+    struct ::timeval now_timeval;
+    ::gettimeofday(&now_timeval, nullptr);
+    const std::time_t now_seconds = now_timeval.tv_sec;
+    struct std::tm now_components;
+    ::localtime_r(&now_seconds, &now_components);
+
     const uint64_t thread_id = (*gettid_)();
 
-    // 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;
-
-      struct timeval now_tv;
-      gettimeofday(&now_tv, nullptr);
-      const time_t seconds = now_tv.tv_sec;
-      struct tm t;
-      localtime_r(&seconds, &t);
-      p += snprintf(p, limit - p,
-                    "%04d/%02d/%02d-%02d:%02d:%02d.%06d %llx ",
-                    t.tm_year + 1900,
-                    t.tm_mon + 1,
-                    t.tm_mday,
-                    t.tm_hour,
-                    t.tm_min,
-                    t.tm_sec,
-                    static_cast<int>(now_tv.tv_usec),
-                    static_cast<long long unsigned int>(thread_id));
-
-      // Print the message
-      if (p < limit) {
-        va_list backup_ap;
-        va_copy(backup_ap, ap);
-        p += vsnprintf(p, limit - p, format, backup_ap);
-        va_end(backup_ap);
-      }
+    // We first attempt to print into a stack-allocated buffer. If this attempt
+    // fails, we make a second attempt with a dynamically allocated buffer.
+    constexpr const int kStackBufferSize = 512;
+    char stack_buffer[kStackBufferSize];
+    static_assert(sizeof(stack_buffer) == static_cast<size_t>(kStackBufferSize),
+                  "sizeof(char) is expected to be 1 in C++");
 
-      // Truncate to available space if necessary
-      if (p >= limit) {
-        if (iter == 0) {
-          continue;       // Try again with larger buffer
-        } else {
-          p = limit - 1;
+    int dynamic_buffer_size = 0;  // Computed in the first iteration.
+    for (int iteration = 0; iteration < 2; ++iteration) {
+      const int buffer_size =
+          (iteration == 0) ? kStackBufferSize : dynamic_buffer_size;
+      char* const buffer =
+          (iteration == 0) ? stack_buffer : new char[dynamic_buffer_size];
+
+      // Print the header into the buffer.
+      int buffer_offset = snprintf(
+          buffer, buffer_size,
+          "%04d/%02d/%02d-%02d:%02d:%02d.%06d %" PRIx64 " ",
+          now_components.tm_year + 1900,
+          now_components.tm_mon + 1,
+          now_components.tm_mday,
+          now_components.tm_hour,
+          now_components.tm_min,
+          now_components.tm_sec,
+          static_cast<int>(now_timeval.tv_usec),
+          thread_id);
+
+      // The header can be at most 48 characters (10 date + 15 time + 3 spacing
+      // + 20 thread ID), which should fit comfortably into the static buffer.
+      assert(buffer_offset <= 48);
+      static_assert(48 < kStackBufferSize,
+                    "stack-allocated buffer may not fit the message header");
+      assert(buffer_offset < buffer_size);
+
+      // Print the message into the buffer.
+      std::va_list arguments_copy;
+      va_copy(arguments_copy, arguments);
+      buffer_offset += std::vsnprintf(buffer + buffer_offset,
+                                      buffer_size - buffer_offset, format,
+                                      arguments_copy);
+      va_end(arguments_copy);
+
+      // The code below may append a newline at the end of the buffer, which
+      // requires an extra character.
+      if (buffer_offset >= buffer_size - 1) {
+        // The message did not fit into the buffer.
+        if (iteration == 0) {
+          // Re-run the loop and use a dynamically-allocated buffer. The buffer
+          // will be large enough for the log message, an extra newline and a
+          // null terminator.
+          dynamic_buffer_size = buffer_offset + 2;
+          continue;
         }
+
+        // The dynamically-allocated buffer was incorrectly sized. This should
+        // not happen, assuming a correct implementation of (v)snprintf. Fail
+        // in tests, recover by truncating the log message in production.
+        assert(false);
+        buffer_offset = buffer_size - 1;
       }
 
-      // Add newline if necessary
-      if (p == base || p[-1] != '\n') {
-        *p++ = '\n';
+      // Add a newline if necessary.
+      if (buffer[buffer_offset - 1] != '\n') {
+        buffer[buffer_offset] = '\n';
+        ++buffer_offset;
       }
 
-      assert(p <= limit);
-      fwrite(base, 1, p - base, file_);
-      fflush(file_);
-      if (base != buffer) {
-        delete[] base;
+      assert(buffer_offset <= buffer_size);
+      std::fwrite(buffer, 1, buffer_offset, fp_);
+      std::fflush(fp_);
+
+      if (iteration != 0) {
+        delete[] buffer;
       }
       break;
     }
   }
+
+ private:
+  std::FILE* const fp_;
+  uint64_t (* const gettid_)();  // Return the thread id for the current thread.
 };
 
 }  // namespace leveldb