fix: unify LogMessage and LogMessageInfo (#1057)

Deprecate the custom prefix callback accepting LogMessageInfo in favor
of existing LogMessage data structure extended with necessary data
fields to avoid redundancies.

.bazelci/presubmit.yml

@@ -1,8 +1,8 @@
 ---
 tasks:
   ubuntu1804:
-    name: "Ubuntu 18.04"
+    name: "Ubuntu 22.04"
-    platform: ubuntu1804
+    platform: ubuntu2204
     build_flags:
     - "--features=layering_check"
     - "--copt=-Werror"

README.rst

@@ -320,6 +320,54 @@ Example:
    caution when comparing the low bits of timestamps from different machines.
 
 
+Customizing the Log Line Prefix
+~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+
+The predefined log line prefix can be replaced using a user-provided callback
+that formats the corresponding output.
+
+For each log entry, the callback will be invoked with a reference to a
+``google::LogMessage`` instance containing the severity, filename, line number,
+thread ID, and time of the event. It will also be given a reference to the
+output stream, whose contents will be prepended to the actual message in the
+final log line.
+
+For example, the following function outputs a prefix that matches glog's default
+format. The third parameter ``data`` can be used to access user-supplied data
+which unless specified defaults to :cpp:`nullptr`.
+
+.. code:: cpp
+
+    void MyPrefixFormatter(std::ostream& s, const google::LogMessage& m, void* /*data*/) {
+       s << google::GetLogSeverityName(m.severity())[0]
+       << setw(4) << 1900 + m.time().year()
+       << setw(2) << 1 + m.time().month()
+       << setw(2) << m.time().day()
+       << ' '
+       << setw(2) << m.time().hour() << ':'
+       << setw(2) << m.time().min()  << ':'
+       << setw(2) << m.time().sec() << "."
+       << setw(6) << m.time().usec()
+       << ' '
+       << setfill(' ') << setw(5)
+       << m.thread_id() << setfill('0')
+       << ' '
+       << m.basename() << ':' << m.line() << "]";
+    }
+
+
+To enable the use of a prefix formatter, use the
+
+.. code:: cpp
+
+    google::InstallPrefixFormatter(&MyPrefixFormatter);
+
+function to pass a pointer to the corresponding :cpp:`MyPrefixFormatter`
+callback during initialization. :cpp:`InstallPrefixFormatter` takes a second
+optional argument of type  :cpp:`void*` that allows supplying user data to the
+callback.
+
+
 Setting Flags
 ~~~~~~~~~~~~~
 
@@ -650,50 +698,6 @@ severity level.
          "Present occurrence is " << google::COUNTER;
 
 
-Custom Log Prefix Format
-~~~~~~~~~~~~~~~~~~~~~~~~
-
-glog supports changing the format of the prefix attached to log messages by
-receiving a user-provided callback that generates such strings.
-
-For each log entry, the callback will be invoked with a ``LogMessageInfo``
-struct containing the severity, filename, line number, thread ID, and time of
-the event. It will also be given a reference to the output stream, whose
-contents will be prepended to the actual message in the final log line.
-
-For example, the following function outputs a prefix that matches glog's default
-format. The third parameter ``data`` can be used to access user-supplied data
-which unless specified defaults to :cpp:`nullptr`.
-
-.. code:: cpp
-
-    void CustomPrefix(std::ostream& s, const LogMessageInfo& l, void* /*data*/) {
-       s << l.severity[0]
-       << setw(4) << 1900 + l.time.year()
-       << setw(2) << 1 + l.time.month()
-       << setw(2) << l.time.day()
-       << ' '
-       << setw(2) << l.time.hour() << ':'
-       << setw(2) << l.time.min()  << ':'
-       << setw(2) << l.time.sec() << "."
-       << setw(6) << l.time.usec()
-       << ' '
-       << setfill(' ') << setw(5)
-       << l.thread_id << setfill('0')
-       << ' '
-       << l.filename << ':' << l.line_number << "]";
-    }
-
-
-To enable the use of a custom prefix, use the
-
-.. code:: cpp
-
-    InitGoogleLogging(argv[0], &CustomPrefix);
-
-overload to pass a pointer to the corresponding :cpp:`CustomPrefix` function during
-initialization. :cpp:`InitGoogleLogging()` takes a third optional argument of
-type  :cpp:`void*` that allows supplying user data to the callback.
 
 Failure Signal Handler
 ~~~~~~~~~~~~~~~~~~~~~~

src/glog/logging.h

@@ -115,7 +115,7 @@ struct GLOG_EXPORT LogMessageTime {
   std::chrono::seconds gmtoffset_;
 };
 
-struct LogMessageInfo {
+struct [[deprecated("Use LogMessage instead.")]] LogMessageInfo {
   explicit LogMessageInfo(const char* const severity_,
                           const char* const filename_, const int& line_number_,
                           std::thread::id thread_id_,
@@ -133,9 +133,6 @@ struct LogMessageInfo {
   const LogMessageTime& time;
 };
 
-typedef void (*CustomPrefixCallback)(std::ostream& s, const LogMessageInfo& l,
-                                     void* data);
-
 }  // namespace google
 
 // The global value of GOOGLE_STRIP_LOG. All the messages logged to
@@ -485,8 +482,25 @@ namespace google {
 // specified by argv0 in log outputs.
 GLOG_EXPORT void InitGoogleLogging(const char* argv0);
 
-GLOG_EXPORT void InitGoogleLogging(const char* argv0,
+class LogMessage;
-                                   CustomPrefixCallback prefix_callback,
+
+#if defined(__GNUG__)
+#  pragma GCC diagnostic push
+#  pragma GCC diagnostic ignored "-Wdeprecated-declarations"
+#elif defined(_MSC_VER)
+#  pragma warning(push)
+#  pragma warning(disable : 4996)
+#endif  // __GNUG__
+using CustomPrefixCallback
+    [[deprecated("Use PrefixFormatterCallback instead.")]] =
+        void (*)(std::ostream&, const LogMessageInfo&, void*);
+#if defined(__GNUG__)
+#  pragma GCC diagnostic pop
+#elif defined(_MSC_VER)
+#  pragma warning(pop)
+#endif  // __GNUG__
+[[deprecated("Use InstallPrefixFormatter instead.")]] GLOG_EXPORT void
+InitGoogleLogging(const char* argv0, CustomPrefixCallback prefix_callback,
                   void* prefix_callback_data = nullptr);
 
 // Check if google's logging library has been initialized.
@@ -501,6 +515,12 @@ typedef void (*logging_fail_func_t)() __attribute__((noreturn));
 typedef void (*logging_fail_func_t)();
 #endif
 
+using PrefixFormatterCallback = void (*)(std::ostream&, const LogMessage&,
+                                         void*);
+
+GLOG_EXPORT void InstallPrefixFormatter(PrefixFormatterCallback callback,
+                                        void* data = nullptr);
+
 // Install a function which will be called after LOG(FATAL).
 GLOG_EXPORT void InstallFailureFunction(logging_fail_func_t fail_func);
 
@@ -1343,9 +1363,15 @@ class GLOG_EXPORT LogMessage {
     return time();
   }
 
-  const LogMessageTime& time() const;
+  LogSeverity severity() const noexcept;
+  int line() const noexcept;
+  const std::thread::id& thread_id() const noexcept;
+  const char* fullname() const noexcept;
+  const char* basename() const noexcept;
+  const LogMessageTime& time() const noexcept;
 
-  struct LogMessageData;
+  LogMessage(const LogMessage&) = delete;
+  LogMessage& operator=(const LogMessage&) = delete;
 
  private:
   // Fully internal SendMethod cases:
@@ -1373,9 +1399,6 @@ class GLOG_EXPORT LogMessage {
   LogMessageTime time_;
 
   friend class LogDestination;
-
-  LogMessage(const LogMessage&);
-  void operator=(const LogMessage&);
 };
 
 // This class happens to be thread-hostile because all instances share
@@ -1493,7 +1516,7 @@ class GLOG_EXPORT LogSink {
   // during this call.
   virtual void send(LogSeverity severity, const char* full_filename,
                     const char* base_filename, int line,
-                    const LogMessageTime& logmsgtime, const char* message,
+                    const LogMessageTime& time, const char* message,
                     size_t message_len);
   // Provide an overload for compatibility purposes
   GLOG_DEPRECATED
@@ -1519,8 +1542,8 @@ class GLOG_EXPORT LogSink {
   // Returns the normal text output of the log message.
   // Can be useful to implement send().
   static std::string ToString(LogSeverity severity, const char* file, int line,
-                              const LogMessageTime& logmsgtime,
+                              const LogMessageTime& time, const char* message,
-                              const char* message, size_t message_len);
+                              size_t message_len);
 };
 
 // Add or remove a LogSink as a consumer of logging data.  Thread-safe.

src/logging.cc

@@ -307,10 +307,10 @@ struct LogMessageData {
   const char* fullname_;        // fullname of file that called LOG
   bool has_been_flushed_;       // false => data has not been flushed
   bool first_fatal_;            // true => this was first fatal msg
+  std::thread::id thread_id_;
 
- private:
   LogMessageData(const LogMessageData&) = delete;
-  void operator=(const LogMessageData&) = delete;
+  LogMessageData& operator=(const LogMessageData&) = delete;
 };
 }  // namespace internal
 }  // namespace logging
@@ -370,9 +370,78 @@ constexpr std::intmax_t kSecondsInDay = 60 * 60 * 24;
 constexpr std::intmax_t kSecondsInWeek = kSecondsInDay * 7;
 
 // Optional user-configured callback to print custom prefixes.
-CustomPrefixCallback custom_prefix_callback = nullptr;
+class PrefixFormatter {
+ public:
+#if defined(__GNUG__)
+#  pragma GCC diagnostic push
+#  pragma GCC diagnostic ignored "-Wdeprecated-declarations"
+#elif defined(_MSC_VER)
+#  pragma warning(push)
+#  pragma warning(disable : 4996)
+#endif  // __GNUG__
+  PrefixFormatter(CustomPrefixCallback callback, void* data) noexcept
+      : version{V1}, callback_v1{callback}, data{data} {}
+#if defined(__GNUG__)
+#  pragma GCC diagnostic pop
+#elif defined(_MSC_VER)
+#  pragma warning(pop)
+#endif  // __GNUG__
+  PrefixFormatter(PrefixFormatterCallback callback, void* data) noexcept
+      : version{V2}, callback_v2{callback}, data{data} {}
+
+  void operator()(std::ostream& s, const LogMessage& message) const {
+    switch (version) {
+      case V1:
+#if defined(__GNUG__)
+#  pragma GCC diagnostic push
+#  pragma GCC diagnostic ignored "-Wdeprecated-declarations"
+#elif defined(_MSC_VER)
+#  pragma warning(push)
+#  pragma warning(disable : 4996)
+#endif  // __GNUG__
+        callback_v1(s,
+                    LogMessageInfo(LogSeverityNames[message.severity()],
+                                   message.basename(), message.line(),
+                                   message.thread_id(), message.time()),
+                    data);
+#if defined(__GNUG__)
+#  pragma GCC diagnostic pop
+#elif defined(_MSC_VER)
+#  pragma warning(pop)
+#endif  // __GNUG__
+        break;
+      case V2:
+        callback_v2(s, message, data);
+        break;
+    }
+  }
+
+  PrefixFormatter(const PrefixFormatter& other) = delete;
+  PrefixFormatter& operator=(const PrefixFormatter& other) = delete;
+
+ private:
+  enum Version { V1, V2 } version;
+  union {
+#if defined(__GNUG__)
+#  pragma GCC diagnostic push
+#  pragma GCC diagnostic ignored "-Wdeprecated-declarations"
+#elif defined(_MSC_VER)
+#  pragma warning(push)
+#  pragma warning(disable : 4996)
+#endif  // __GNUG__
+    CustomPrefixCallback callback_v1;
+#if defined(__GNUG__)
+#  pragma GCC diagnostic pop
+#elif defined(_MSC_VER)
+#  pragma warning(pop)
+#endif  // __GNUG__
+    PrefixFormatterCallback callback_v2;
+  };
   // User-provided data to pass to the callback:
-void* custom_prefix_callback_data = nullptr;
+  void* data;
+};
+
+std::unique_ptr<PrefixFormatter> g_prefix_formatter;
 
 // Encapsulates all file-system related state
 class LogFileObject : public base::Logger {
@@ -544,7 +613,7 @@ class LogDestination {
   // Send logging info to all registered sinks.
   static void LogToSinks(LogSeverity severity, const char* full_filename,
                          const char* base_filename, int line,
-                         const LogMessageTime& logmsgtime, const char* message,
+                         const LogMessageTime& time, const char* message,
                          size_t message_len);
 
   // Wait for all registered sinks via WaitTillSent
@@ -844,14 +913,14 @@ inline void LogDestination::LogToAllLogfiles(
 inline void LogDestination::LogToSinks(LogSeverity severity,
                                        const char* full_filename,
                                        const char* base_filename, int line,
-                                       const LogMessageTime& logmsgtime,
+                                       const LogMessageTime& time,
                                        const char* message,
                                        size_t message_len) {
   std::shared_lock<SinkMutex> l{sink_mutex_};
   if (sinks_) {
     for (size_t i = sinks_->size(); i-- > 0;) {
-      (*sinks_)[i]->send(severity, full_filename, base_filename, line,
+      (*sinks_)[i]->send(severity, full_filename, base_filename, line, time,
-                         logmsgtime, message, message_len);
+                         message, message_len);
     }
   }
 }
@@ -1602,6 +1671,7 @@ void LogMessage::Init(const char* file, int line, LogSeverity severity,
   data_->basename_ = const_basename(file);
   data_->fullname_ = file;
   data_->has_been_flushed_ = false;
+  data_->thread_id_ = std::this_thread::get_id();
 
   // If specified, prepend a prefix to each line.  For example:
   //    I20201018 160715 f5d4fbb0 logging.cc:1153]
@@ -1611,7 +1681,7 @@ void LogMessage::Init(const char* file, int line, LogSeverity severity,
     std::ios saved_fmt(nullptr);
     saved_fmt.copyfmt(stream());
     stream().fill('0');
-    if (custom_prefix_callback == nullptr) {
+    if (g_prefix_formatter == nullptr) {
       stream() << LogSeverityNames[severity][0];
       if (FLAGS_log_year_in_prefix) {
         stream() << setw(4) << 1900 + time_.year();
@@ -1620,14 +1690,10 @@ void LogMessage::Init(const char* file, int line, LogSeverity severity,
                << setw(2) << time_.hour() << ':' << setw(2) << time_.min()
                << ':' << setw(2) << time_.sec() << "." << setw(6)
                << time_.usec() << ' ' << setfill(' ') << setw(5)
-               << std::this_thread::get_id() << setfill('0') << ' '
+               << data_->thread_id_ << setfill('0') << ' ' << data_->basename_
-               << data_->basename_ << ':' << data_->line_ << "] ";
+               << ':' << data_->line_ << "] ";
     } else {
-      custom_prefix_callback(
+      (*g_prefix_formatter)(stream(), *this);
-          stream(),
-          LogMessageInfo(LogSeverityNames[severity], data_->basename_,
-                         data_->line_, std::this_thread::get_id(), time_),
-          custom_prefix_callback_data);
       stream() << " ";
     }
     stream().copyfmt(saved_fmt);
@@ -1647,7 +1713,15 @@ void LogMessage::Init(const char* file, int line, LogSeverity severity,
   }
 }
 
-const LogMessageTime& LogMessage::time() const { return time_; }
+LogSeverity LogMessage::severity() const noexcept { return data_->severity_; }
+
+int LogMessage::line() const noexcept { return data_->line_; }
+const std::thread::id& LogMessage::thread_id() const noexcept {
+  return data_->thread_id_;
+}
+const char* LogMessage::fullname() const noexcept { return data_->fullname_; }
+const char* LogMessage::basename() const noexcept { return data_->basename_; }
+const LogMessageTime& LogMessage::time() const noexcept { return time_; }
 
 LogMessage::~LogMessage() {
   Flush();
@@ -2039,21 +2113,20 @@ void LogSink::WaitTillSent() {
 }
 
 string LogSink::ToString(LogSeverity severity, const char* file, int line,
-                         const LogMessageTime& logmsgtime, const char* message,
+                         const LogMessageTime& time, const char* message,
                          size_t message_len) {
   ostringstream stream;
   stream.fill('0');
 
   stream << LogSeverityNames[severity][0];
   if (FLAGS_log_year_in_prefix) {
-    stream << setw(4) << 1900 + logmsgtime.year();
+    stream << setw(4) << 1900 + time.year();
   }
-  stream << setw(2) << 1 + logmsgtime.month() << setw(2) << logmsgtime.day()
+  stream << setw(2) << 1 + time.month() << setw(2) << time.day() << ' '
-         << ' ' << setw(2) << logmsgtime.hour() << ':' << setw(2)
+         << setw(2) << time.hour() << ':' << setw(2) << time.min() << ':'
-         << logmsgtime.min() << ':' << setw(2) << logmsgtime.sec() << '.'
+         << setw(2) << time.sec() << '.' << setw(6) << time.usec() << ' '
-         << setw(6) << logmsgtime.usec() << ' ' << setfill(' ') << setw(5)
+         << setfill(' ') << setw(5) << std::this_thread::get_id()
-         << std::this_thread::get_id() << setfill('0') << ' ' << file << ':'
+         << setfill('0') << ' ' << file << ':' << line << "] ";
-         << line << "] ";
 
   // A call to `write' is enclosed in parenthneses to prevent possible macro
   // expansion.  On Windows, `write' could be a macro defined for portability.
@@ -2624,17 +2697,42 @@ void MakeCheckOpValueString(std::ostream* os, const std::nullptr_t& /*v*/) {
 
 void InitGoogleLogging(const char* argv0) { InitGoogleLoggingUtilities(argv0); }
 
+#if defined(__GNUG__)
+#  pragma GCC diagnostic push
+#  pragma GCC diagnostic ignored "-Wdeprecated-declarations"
+#elif defined(_MSC_VER)
+#  pragma warning(push)
+#  pragma warning(disable : 4996)
+#endif  // __GNUG__
 void InitGoogleLogging(const char* argv0, CustomPrefixCallback prefix_callback,
                        void* prefix_callback_data) {
-  custom_prefix_callback = prefix_callback;
+  if (prefix_callback != nullptr) {
-  custom_prefix_callback_data = prefix_callback_data;
+    g_prefix_formatter = std::make_unique<PrefixFormatter>(
+        prefix_callback, prefix_callback_data);
+  } else {
+    g_prefix_formatter = nullptr;
+  }
   InitGoogleLogging(argv0);
 }
+#if defined(__GNUG__)
+#  pragma GCC diagnostic pop
+#elif defined(_MSC_VER)
+#  pragma warning(pop)
+#endif  // __GNUG__
+
+void InstallPrefixFormatter(PrefixFormatterCallback callback, void* data) {
+  if (callback != nullptr) {
+    g_prefix_formatter = std::make_unique<PrefixFormatter>(callback, data);
+  } else {
+    g_prefix_formatter = nullptr;
+  }
+}
 
 void ShutdownGoogleLogging() {
   ShutdownGoogleLoggingUtilities();
   LogDestination::DeleteLogDestinations();
   logging_directories_list = nullptr;
+  g_prefix_formatter = nullptr;
 }
 
 void EnableLogCleaner(unsigned int overdue_days) {

src/logging_unittest.cc

@@ -185,23 +185,27 @@ static void BM_vlog(int n) {
 }
 BENCHMARK(BM_vlog)
 
+namespace {
+
 // Dynamically generate a prefix using the default format and write it to the
 // stream.
-void PrefixAttacher(std::ostream& s, const LogMessageInfo& l, void* data) {
+void PrefixAttacher(std::ostream& s, const LogMessage& m, void* data) {
   // Assert that `data` contains the expected contents before producing the
   // prefix (otherwise causing the tests to fail):
   if (data == nullptr || *static_cast<string*>(data) != "good data") {
     return;
   }
 
-  s << l.severity[0] << setw(4) << 1900 + l.time.year() << setw(2)
+  s << GetLogSeverityName(m.severity())[0] << setw(4) << 1900 + m.time().year()
-    << 1 + l.time.month() << setw(2) << l.time.day() << ' ' << setw(2)
+    << setw(2) << 1 + m.time().month() << setw(2) << m.time().day() << ' '
-    << l.time.hour() << ':' << setw(2) << l.time.min() << ':' << setw(2)
+    << setw(2) << m.time().hour() << ':' << setw(2) << m.time().min() << ':'
-    << l.time.sec() << "." << setw(6) << l.time.usec() << ' ' << setfill(' ')
+    << setw(2) << m.time().sec() << "." << setw(6) << m.time().usec() << ' '
-    << setw(5) << l.thread_id << setfill('0') << ' ' << l.filename << ':'
+    << setfill(' ') << setw(5) << m.thread_id() << setfill('0') << ' '
-    << l.line_number << "]";
+    << m.basename() << ':' << m.line() << "]";
 }
 
+}  // namespace
+
 int main(int argc, char** argv) {
   FLAGS_colorlogtostderr = false;
   FLAGS_timestamp_in_logfile_name = true;
@@ -222,8 +226,8 @@ int main(int argc, char** argv) {
   // Setting a custom prefix generator (it will use the default format so that
   // the golden outputs can be reused):
   string prefix_attacher_data = "good data";
-  InitGoogleLogging(argv[0], &PrefixAttacher,
+  InitGoogleLogging(argv[0]);
-                    static_cast<void*>(&prefix_attacher_data));
+  InstallPrefixFormatter(&PrefixAttacher, &prefix_attacher_data);
 
   EXPECT_TRUE(IsGoogleLoggingInitialized());