Upgrade logging to resemble base/logging.h.

First phase of extending the relocation packer for arm64.

Upgrade logging to be streams-based.  Add new unit tests to cover logging
and checking features.  Mechanical changes to logging call sites.

Also correct a type promotion issue that causes incorrect DT_RELCOUNT
adjustments when the packer is compiled as a 32-bit Linux binary.

BUG=385553

Review URL: https://codereview.chromium.org/392653002

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@283552 0039d316-1c4b-4281-b951-d872f2087c98

tools/relocation_packer/relocation_packer.gyp

@@ -46,6 +46,7 @@
         '../..',
       ],
       'sources': [
+        'src/debug_unittest.cc',
         'src/elf_file_unittest.cc',
         'src/leb128_unittest.cc',
         'src/packer_unittest.cc',

tools/relocation_packer/src/debug.cc

@@ -2,43 +2,54 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
-#include <stdarg.h>
-#include <stdio.h>
-
 #include "debug.h"
 
-namespace relocation_packer {
+#include <stdlib.h>
+#include <iostream>
+#include <string>
 
-Logger* Logger::instance_ = NULL;
+namespace relocation_packer {
 
-Logger* Logger::GetInstance() {
-  if (instance_ == NULL)
-    instance_ = new Logger;
-  return instance_;
+// Construct a new message logger.  Prints if level is less than or equal to
+// the level set with SetVerbose() and predicate is true.
+Logger::Logger(Severity severity, int level, bool predicate) {
+  severity_ = severity;
+  level_ = level;
+  predicate_ = predicate;
 }
 
-void Logger::Log(const char* format, va_list args) {
-  vfprintf(stdout, format, args);
+// On destruction, flush and print the strings accumulated.  Abort if FATAL.
+Logger::~Logger() {
+  if (predicate_) {
+    if (level_ <= max_level_) {
+      std::ostream* log = severity_ == INFO ? info_stream_ : error_stream_;
+      std::string tag;
+      switch (severity_) {
+        case INFO: tag = "INFO"; break;
+        case WARNING: tag = "WARNING"; break;
+        case ERROR: tag = "ERROR"; break;
+        case FATAL: tag = "FATAL"; break;
+      }
+      stream_.flush();
+      *log << tag << ": " << stream_.str() << std::endl;
+    }
+    if (severity_ == FATAL)
+      abort();
+  }
 }
 
-void Logger::Log(const char* format, ...) {
-  va_list args;
-  va_start(args, format);
-  GetInstance()->Log(format, args);
-  va_end(args);
+// Reset to initial state.
+void Logger::Reset() {
+  max_level_ = -1;
+  info_stream_ = &std::cout;
+  error_stream_ = &std::cerr;
 }
 
-void Logger::VLog(const char* format, ...) {
-  if (GetInstance()->is_verbose_) {
-    va_list args;
-    va_start(args, format);
-    GetInstance()->Log(format, args);
-    va_end(args);
-  }
-}
+// Verbosity.  Not thread-safe.
+int Logger::max_level_ = -1;
 
-void Logger::SetVerbose(bool flag) {
-  GetInstance()->is_verbose_ = flag;
-}
+// Logging streams.  Not thread-safe.
+std::ostream* Logger::info_stream_ = &std::cout;
+std::ostream* Logger::error_stream_ = &std::cerr;
 
 }  // namespace relocation_packer

tools/relocation_packer/src/debug.h

@@ -2,87 +2,115 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
-// Logging and checks.
+// Logging and checks.  Avoids a dependency on base.
 //
-// Log messages to stdout.  LOG() prints normal user messages, VLOG()
-// is verbose, for tracing and debugging.  SetVerbose() enables/disables
-// VLOG() output.
+// LOG(tag) prints messages.  Tags are INFO, WARNING, ERROR and FATAL.
+// INFO prints to stdout, the others to stderr.  FATAL aborts after printing.
 //
-// LOG() and VLOG() are printf-like, and arguments are checked by gcc.
-// LOG_IF() and VLOG_IF() call LOG/VLOG if their predicate is true.
-// CHECK() aborts if its predicate is false.  NOTREACHED() always aborts.
-// Logging is not thread-safe.
+// LOG_IF(tag, predicate) logs if predicate evaluates to true, else silent.
+//
+// VLOG(level) logs INFO messages where level is less than or equal to the
+// verbosity level set with SetVerbose().
+//
+// VLOG_IF(level, predicate) logs INFO if predicate evaluates to true,
+// else silent.
+//
+// CHECK(predicate) logs a FATAL error if predicate is false.
+// NOTREACHED() always aborts.
+// Log streams can be changed with SetStreams().  Logging is not thread-safe.
 //
 
 #ifndef TOOLS_RELOCATION_PACKER_SRC_DEBUG_H_
 #define TOOLS_RELOCATION_PACKER_SRC_DEBUG_H_
 
-#ifdef NDEBUG
-#undef NDEBUG
-#include <assert.h>
-#define NDEBUG
-#else
-#include <assert.h>
-#endif
-
-#include <stdarg.h>
-#include <string.h>
+#include <limits.h>
+#include <algorithm>
+#include <ostream>
+#include <sstream>
 
 namespace relocation_packer {
 
-// If gcc, define PRINTF_ATTRIBUTE so that gcc checks Log() as printf-like.
-#if defined(__GNUC__) && (__GNUC__ >= 3)
-#define PRINTF_ATTRIBUTE(string_index, first_to_check) \
-    __attribute__((__format__(__printf__, string_index, first_to_check)))
-#else
-#define PRINTF_ATTRIBUTE(string_index, first_to_check)
-#endif
-
-// Logging and checking macros.
-#define LOG(...) ::relocation_packer::Logger::Log(__VA_ARGS__)
-#define VLOG(...) ::relocation_packer::Logger::VLog(__VA_ARGS__)
-#define LOG_IF(cond, ...)  \
-  do {                     \
-    if ((cond))            \
-      LOG(__VA_ARGS__);    \
-  } while (0)
-#define VLOG_IF(cond, ...) \
-  do {                     \
-    if ((cond))            \
-      VLOG(__VA_ARGS__);   \
-  } while (0)
-
-#define CHECK(expr) assert((expr))
-#define NOTREACHED(_) assert(false)
-
 class Logger {
  public:
-  // Log and verbose log to stdout.
-  // |format| is a printf format string.
-  static void Log(const char* format, ...) PRINTF_ATTRIBUTE(1, 2);
-  static void VLog(const char* format, ...) PRINTF_ATTRIBUTE(1, 2);
+  enum Severity {INFO = 0, WARNING, ERROR, FATAL};
+
+  // Construct a new message logger.  Prints if level is less than or
+  // equal to the level set with SetVerbose() and predicate is true.
+  // |severity| is an enumerated severity.
+  // |level| is the verbosity level.
+  // |predicate| controls if the logger prints or is silent.
+  Logger(Severity severity, int level, bool predicate);
 
-  // Set verbose mode.
-  // |flag| is true to enable verbose logging, false to disable it.
-  static void SetVerbose(bool flag);
+  // On destruction, flush and print the strings accumulated in stream_.
+  ~Logger();
+
+  // Return the stream for this logger.
+  std::ostream& GetStream() { return stream_; }
+
+  // Set verbosity level.  Messages with a level less than or equal to
+  // this level are printed, others are discarded.  Static, not thread-safe.
+  static void SetVerbose(int level) { max_level_ = level; }
+
+  // Set info and error logging streams.  Static, not thread-safe.
+  static void SetStreams(std::ostream* info_stream,
+                         std::ostream* error_stream) {
+    info_stream_ = info_stream;
+    error_stream_ = error_stream;
+  }
+
+  // Reset to initial state.
+  static void Reset();
 
  private:
-  Logger() : is_verbose_(false) { }
-  ~Logger() {}
+  // Message severity, verbosity level, and predicate.
+  Severity severity_;
+  int level_;
+  bool predicate_;
 
-  // Implementation of log to stdout.
-  // |format| is a printf format string.
-  // |args| is a varargs list of printf arguments.
-  void Log(const char* format, va_list args);
+  // String stream, accumulates message text.
+  std::ostringstream stream_;
 
-  // If set, VLOG is enabled, otherwise it is a no-op.
-  bool is_verbose_;
+  // Verbosity for INFO messages.  Not thread-safe.
+  static int max_level_;
 
-  // Singleton support.  Not thread-safe.
-  static Logger* GetInstance();
-  static Logger* instance_;
+  // Logging streams.  Not thread-safe.
+  static std::ostream* info_stream_;
+  static std::ostream* error_stream_;
 };
 
 }  // namespace relocation_packer
 
+// Make logging severities visible globally.
+typedef relocation_packer::Logger::Severity LogSeverity;
+const LogSeverity INFO = relocation_packer::Logger::INFO;
+const LogSeverity WARNING = relocation_packer::Logger::WARNING;
+const LogSeverity ERROR = relocation_packer::Logger::ERROR;
+const LogSeverity FATAL = relocation_packer::Logger::FATAL;
+
+// LOG(severity) prints a message with the given severity, and aborts if
+// severity is FATAL.  LOG_IF(severity, predicate) does the same but only if
+// predicate is true.  INT_MIN is guaranteed to be less than or equal to
+// any verbosity level.
+#define LOG(severity) \
+    (relocation_packer::Logger(severity, INT_MIN, true).GetStream())
+#define LOG_IF(severity, predicate) \
+    (relocation_packer::Logger(severity, INT_MIN, (predicate)).GetStream())
+
+// VLOG(level) prints its message as INFO if level is less than or equal to
+// the current verbosity level.
+#define VLOG(level) \
+    (relocation_packer::Logger(INFO, (level), true).GetStream())
+#define VLOG_IF(level, predicate) \
+    (relocation_packer::Logger(INFO, (level), (predicate)).GetStream())
+
+// CHECK(predicate) fails with a FATAL log message if predicate is false.
+#define CHECK(predicate) (LOG_IF(FATAL, !(predicate)) \
+    << __FILE__ << ":" << __LINE__ << ": " \
+    << __FUNCTION__ << ": CHECK '" #predicate "' failed")
+
+// NOTREACHED() always fails with a FATAL log message.
+#define NOTREACHED(_) (LOG(FATAL) \
+    << __FILE__ << ":" << __LINE__ << ": " \
+    << __FUNCTION__ << ": NOTREACHED() hit")
+
 #endif  // TOOLS_RELOCATION_PACKER_SRC_DEBUG_H_

tools/relocation_packer/src/debug_unittest.cc

+// Copyright 2014 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "debug.h"
+
+#include <sstream>
+#include <string>
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace relocation_packer {
+
+TEST(Debug, Log) {
+  Logger::Reset();
+  std::ostringstream info;
+  std::ostringstream error;
+  Logger::SetStreams(&info, &error);
+
+  LOG(INFO) << "INFO log message";
+  LOG(WARNING) << "WARNING log message";
+  LOG(ERROR) << "ERROR log message";
+
+  EXPECT_EQ("INFO: INFO log message\n", info.str());
+  EXPECT_EQ("WARNING: WARNING log message\n"
+            "ERROR: ERROR log message\n", error.str());
+  Logger::Reset();
+}
+
+TEST(Debug, LogIf) {
+  Logger::Reset();
+  std::ostringstream info;
+  std::ostringstream error;
+  Logger::SetStreams(&info, &error);
+
+  LOG_IF(INFO, true) << "INFO log message";
+  LOG_IF(INFO, false) << "INFO log message, SHOULD NOT PRINT";
+  LOG_IF(WARNING, true) << "WARNING log message";
+  LOG_IF(WARNING, false) << "WARNING log message, SHOULD NOT PRINT";
+  LOG_IF(ERROR, true) << "ERROR log message";
+  LOG_IF(ERROR, false) << "ERROR log message, SHOULD NOT PRINT";
+  LOG_IF(FATAL, false) << "FATAL log message, SHOULD NOT PRINT";
+
+  EXPECT_EQ("INFO: INFO log message\n", info.str());
+  EXPECT_EQ("WARNING: WARNING log message\n"
+            "ERROR: ERROR log message\n", error.str());
+  Logger::Reset();
+}
+
+TEST(Debug, Vlog) {
+  Logger::Reset();
+  std::ostringstream info;
+  std::ostringstream error;
+  Logger::SetStreams(&info, &error);
+
+  VLOG(0) << "VLOG 0 INFO log message, SHOULD NOT PRINT";
+  VLOG(1) << "VLOG 1 INFO log message, SHOULD NOT PRINT";
+  VLOG(2) << "VLOG 2 INFO log message, SHOULD NOT PRINT";
+
+  EXPECT_EQ("", info.str());
+  EXPECT_EQ("", error.str());
+
+  Logger::SetVerbose(1);
+
+  VLOG(0) << "VLOG 0 INFO log message";
+  VLOG(1) << "VLOG 1 INFO log message";
+  VLOG(2) << "VLOG 2 INFO log message, SHOULD NOT PRINT";
+
+  EXPECT_EQ("INFO: VLOG 0 INFO log message\n"
+            "INFO: VLOG 1 INFO log message\n", info.str());
+  EXPECT_EQ("", error.str());
+  Logger::Reset();
+}
+
+TEST(Debug, VlogIf) {
+  Logger::Reset();
+  std::ostringstream info;
+  std::ostringstream error;
+  Logger::SetStreams(&info, &error);
+
+  VLOG_IF(0, true) << "VLOG 0 INFO log message, SHOULD NOT PRINT";
+  VLOG_IF(1, true) << "VLOG 1 INFO log message, SHOULD NOT PRINT";
+  VLOG_IF(2, true) << "VLOG 2 INFO log message, SHOULD NOT PRINT";
+
+  EXPECT_EQ("", info.str());
+  EXPECT_EQ("", error.str());
+
+  Logger::SetVerbose(1);
+
+  VLOG_IF(0, true) << "VLOG 0 INFO log message";
+  VLOG_IF(0, false) << "VLOG 0 INFO log message, SHOULD NOT PRINT";
+  VLOG_IF(1, true) << "VLOG 1 INFO log message";
+  VLOG_IF(1, false) << "VLOG 1 INFO log message, SHOULD NOT PRINT";
+  VLOG_IF(2, true) << "VLOG 2 INFO log message, SHOULD NOT PRINT";
+  VLOG_IF(2, false) << "VLOG 2 INFO log message, SHOULD NOT PRINT";
+
+  EXPECT_EQ("INFO: VLOG 0 INFO log message\n"
+            "INFO: VLOG 1 INFO log message\n", info.str());
+  EXPECT_EQ("", error.str());
+  Logger::Reset();
+}
+
+TEST(DebugDeathTest, Fatal) {
+  ::testing::FLAGS_gtest_death_test_style = "threadsafe";
+  Logger::Reset();
+  EXPECT_DEATH(LOG(FATAL) << "FATAL log message", "FATAL: FATAL log message");
+  EXPECT_DEATH(
+      LOG_IF(FATAL, true) << "FATAL log message", "FATAL: FATAL log message");
+}
+
+TEST(DebugDeathTest, Check) {
+  ::testing::FLAGS_gtest_death_test_style = "threadsafe";
+  Logger::Reset();
+  CHECK(0 == 0);
+  EXPECT_DEATH(CHECK(0 == 1), "FATAL: .*:.*: .*: CHECK '0 == 1' failed");
+}
+
+TEST(DebugDeathTest, NotReached) {
+  ::testing::FLAGS_gtest_death_test_style = "threadsafe";
+  Logger::Reset();
+  EXPECT_DEATH(NOTREACHED(), "FATAL: .*:.*: .*: NOTREACHED\\(\\) hit");
+}
+
+}  // namespace relocation_packer

tools/relocation_packer/src/main.cc

@@ -29,7 +29,8 @@
 #include "debug.h"
 #include "elf_file.h"
 #include "libelf.h"
-#include "packer.h"
+
+namespace {
 
 void PrintUsage(const char* argv0) {
   std::string temporary = argv0;
@@ -66,6 +67,8 @@ void PrintUsage(const char* argv0) {
       basename, basename, basename);
 }
 
+}  // namespace
+
 int main(int argc, char* argv[]) {
   bool is_unpacking = false;
   bool is_verbose = false;
@@ -92,7 +95,7 @@ int main(int argc, char* argv[]) {
         PrintUsage(argv[0]);
         return 0;
       case '?':
-        LOG("Try '%s --help' for more information.\n", argv[0]);
+        LOG(INFO) << "Try '" << argv[0] << " --help' for more information.";
         return 1;
       case -1:
         has_options = false;
@@ -102,22 +105,23 @@ int main(int argc, char* argv[]) {
     }
   }
   if (optind != argc - 1) {
-    LOG("Try '%s --help' for more information.\n", argv[0]);
+    LOG(INFO) << "Try '" << argv[0] << " --help' for more information.";
     return 1;
   }
 
   if (elf_version(EV_CURRENT) == EV_NONE) {
-    LOG("WARNING: Elf Library is out of date!\n");
+    LOG(WARNING) << "Elf Library is out of date!";
   }
 
   const char* file = argv[argc - 1];
   const int fd = open(file, O_RDWR);
   if (fd == -1) {
-    LOG("%s: %s\n", file, strerror(errno));
+    LOG(ERROR) << file << ": " << strerror(errno);
     return 1;
   }
 
-  relocation_packer::Logger::SetVerbose(is_verbose);
+  if (is_verbose)
+    relocation_packer::Logger::SetVerbose(1);
 
   relocation_packer::ElfFile elf_file(fd);
   elf_file.SetPadding(is_padding);
@@ -131,7 +135,7 @@ int main(int argc, char* argv[]) {
   close(fd);
 
   if (!status) {
-    LOG("ERROR: %s: failed to pack/unpack file\n", file);
+    LOG(ERROR) << file << ": failed to pack/unpack file";
     return 1;
   }