From 5a5e59a15e00c01ef0536bd507a7435d92b84a61 Mon Sep 17 00:00:00 2001 From: Sergiu Deitsch Date: Tue, 9 Jan 2024 00:47:22 +0100 Subject: [PATCH] fix: unify LogMessage and LogMessageInfo Deprecate the custom prefix callback accepting LogMessageInfo in favor of existing LogMessage data structure extended with necessary data fields to avoid redundancies. --- README.rst | 31 ++++---- src/glog/logging.h | 52 ++++++++++--- src/logging.cc | 161 ++++++++++++++++++++++++++++++++-------- src/logging_unittest.cc | 21 +++--- src/symbolize.cc | 2 +- 5 files changed, 201 insertions(+), 66 deletions(-) diff --git a/README.rst b/README.rst index c247d14dd..8e5770739 100644 --- a/README.rst +++ b/README.rst @@ -656,10 +656,11 @@ 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 each log entry, the callback will be invoked with a reference to a +``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 @@ -667,21 +668,21 @@ 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() + void CustomPrefix(std::ostream& s, const LogMessage& m, void* /*data*/) { + s << GetLogSeverityName(m.severity())[0] + << setw(4) << 1900 + m.time().year() + << setw(2) << 1 + m.time().month() + << setw(2) << m.time().day() << ' ' - << setw(2) << l.time.hour() << ':' - << setw(2) << l.time.min() << ':' - << setw(2) << l.time.sec() << "." - << setw(6) << l.time.usec() + << setw(2) << m.time().hour() << ':' + << setw(2) << m.time().min() << ':' + << setw(2) << m.time().sec() << "." + << setw(6) << m.time().usec() << ' ' << setfill(' ') << setw(5) - << l.thread_id << setfill('0') + << m.thread_id() << setfill('0') << ' ' - << l.filename << ':' << l.line_number << "]"; + << m.basename() << ':' << m.line() << "]"; } diff --git a/src/glog/logging.h b/src/glog/logging.h index f4d6b4dfe..85ccfd302 100644 --- a/src/glog/logging.h +++ b/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,8 +133,28 @@ struct LogMessageInfo { const LogMessageTime& time; }; -typedef void (*CustomPrefixCallback)(std::ostream& s, const LogMessageInfo& l, - void* data); +class LogMessage; + +#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 CustomPrefixCallbackV1 + [[deprecated("Use CustomPrefixCallbackV2 instead.")]] = + void (*)(std::ostream&, const LogMessageInfo&, void*); +using CustomPrefixCallback + [[deprecated("Use CustomPrefixCallbackV2 instead.")]] = + CustomPrefixCallbackV1; +#if defined(__GNUG__) +# pragma GCC diagnostic pop +#elif defined(_MSC_VER) +# pragma warning(pop) +#endif // __GNUG__ +using CustomPrefixCallbackV2 = void (*)(std::ostream&, const LogMessage&, + void*); } // namespace google @@ -485,8 +505,13 @@ namespace google { // specified by argv0 in log outputs. GLOG_EXPORT void InitGoogleLogging(const char* argv0); +[[deprecated( + "Use InitGoogleLogging with the CustomPrefixCallbackV2 overload " + "instead.")]] GLOG_EXPORT void +InitGoogleLogging(const char* argv0, CustomPrefixCallbackV1 prefix_callback, + void* prefix_callback_data = nullptr); GLOG_EXPORT void InitGoogleLogging(const char* argv0, - CustomPrefixCallback prefix_callback, + CustomPrefixCallbackV2 prefix_callback, void* prefix_callback_data = nullptr); // Check if google's logging library has been initialized. @@ -1343,9 +1368,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 +1404,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 +1521,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 +1547,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 char* message, size_t message_len); + const LogMessageTime& time, const char* message, + size_t message_len); }; // Add or remove a LogSink as a consumer of logging data. Thread-safe. diff --git a/src/logging.cc b/src/logging.cc index f9ffa703c..80cc8ba6a 100644 --- a/src/logging.cc +++ b/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; -// User-provided data to pass to the callback: -void* custom_prefix_callback_data = nullptr; +class PrefixCallback { + 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__ + PrefixCallback(CustomPrefixCallbackV1 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__ + PrefixCallback(CustomPrefixCallbackV2 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; + } + } + + PrefixCallback(const PrefixCallback& other) = delete; + PrefixCallback& operator=(const PrefixCallback& 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__ + CustomPrefixCallbackV1 callback_v1; +#if defined(__GNUG__) +# pragma GCC diagnostic pop +#elif defined(_MSC_VER) +# pragma warning(pop) +#endif // __GNUG__ + CustomPrefixCallbackV2 callback_v2; + }; + // User-provided data to pass to the callback: + void* data; +}; + +std::unique_ptr g_prefix_callback; // 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 l{sink_mutex_}; if (sinks_) { for (size_t i = sinks_->size(); i-- > 0;) { - (*sinks_)[i]->send(severity, full_filename, base_filename, line, - logmsgtime, message, message_len); + (*sinks_)[i]->send(severity, full_filename, base_filename, line, time, + 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_callback == 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_->basename_ << ':' << data_->line_ << "] "; + << data_->thread_id_ << setfill('0') << ' ' << data_->basename_ + << ':' << data_->line_ << "] "; } else { - custom_prefix_callback( - stream(), - LogMessageInfo(LogSeverityNames[severity], data_->basename_, - data_->line_, std::this_thread::get_id(), time_), - custom_prefix_callback_data); + (*g_prefix_callback)(stream(), *this); 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() - << ' ' << setw(2) << logmsgtime.hour() << ':' << setw(2) - << logmsgtime.min() << ':' << setw(2) << logmsgtime.sec() << '.' - << setw(6) << logmsgtime.usec() << ' ' << setfill(' ') << setw(5) - << std::this_thread::get_id() << setfill('0') << ' ' << file << ':' - << line << "] "; + stream << setw(2) << 1 + time.month() << setw(2) << time.day() << ' ' + << 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') << ' ' << file << ':' << 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,10 +2697,39 @@ void MakeCheckOpValueString(std::ostream* os, const std::nullptr_t& /*v*/) { void InitGoogleLogging(const char* argv0) { InitGoogleLoggingUtilities(argv0); } -void InitGoogleLogging(const char* argv0, 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__ +void InitGoogleLogging(const char* argv0, + CustomPrefixCallbackV1 prefix_callback, + void* prefix_callback_data) { + if (prefix_callback != nullptr) { + g_prefix_callback = + std::make_unique(prefix_callback, prefix_callback_data); + } else { + g_prefix_callback = nullptr; + } + InitGoogleLogging(argv0); +} +#if defined(__GNUG__) +# pragma GCC diagnostic pop +#elif defined(_MSC_VER) +# pragma warning(pop) +#endif // __GNUG__ + +void InitGoogleLogging(const char* argv0, + CustomPrefixCallbackV2 prefix_callback, void* prefix_callback_data) { - custom_prefix_callback = prefix_callback; - custom_prefix_callback_data = prefix_callback_data; + if (prefix_callback != nullptr) { + g_prefix_callback = + std::make_unique(prefix_callback, prefix_callback_data); + } else { + g_prefix_callback = nullptr; + } InitGoogleLogging(argv0); } @@ -2635,6 +2737,7 @@ void ShutdownGoogleLogging() { ShutdownGoogleLoggingUtilities(); LogDestination::DeleteLogDestinations(); logging_directories_list = nullptr; + g_prefix_callback = nullptr; } void EnableLogCleaner(unsigned int overdue_days) { diff --git a/src/logging_unittest.cc b/src/logging_unittest.cc index dde1fbf89..ff977ef43 100644 --- a/src/logging_unittest.cc +++ b/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(data) != "good data") { return; } - 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 << "]"; + s << 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() << "]"; } +} // namespace + int main(int argc, char** argv) { FLAGS_colorlogtostderr = false; FLAGS_timestamp_in_logfile_name = true; @@ -222,8 +226,7 @@ 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, - static_cast(&prefix_attacher_data)); + InitGoogleLogging(argv[0], &PrefixAttacher, &prefix_attacher_data); EXPECT_TRUE(IsGoogleLoggingInitialized()); diff --git a/src/symbolize.cc b/src/symbolize.cc index 5c78be565..09bc9ebe4 100644 --- a/src/symbolize.cc +++ b/src/symbolize.cc @@ -943,7 +943,7 @@ static ATTRIBUTE_NOINLINE bool SymbolizeAndDemangle(void* pc, char* out, const std::size_t suffixlen = fnlen + extralen + fnlen + digits; if (suffixlen < out_size) { - out_size -= std::snprintf(out + namelen, out_size, " (%s:%u)", + out_size -= std::snprintf(out + namelen, out_size, " (%s:%lu)", line.FileName, line.LineNumber); } }