From cefc46517ecc0db2be0402f4a00aafefe5241529 Mon Sep 17 00:00:00 2001 From: Karl Wiberg Date: Wed, 23 May 2018 23:20:38 +0200 Subject: [PATCH] RTC_LOG_* macros: Implement argument passing with a single variadic call Instead of making multiple calls to the std::stringstream << operator, collect all the arguments and make a single printf-like variadic call under the hood. Besides reducing our reliance on iostreams, this makes each RTC_LOG_* call site smaller; in aggregate, this reduces the size of libjingle_peerconnection_so.so by 28-32 kB. A quick benchmark indicates that this change makes log statements a few percent slower. Bug: webrtc:8982, webrtc:9185 Change-Id: I3137a4dd8ac510e8d910acccb0c97ce4fffb61c9 Reviewed-on: https://webrtc-review.googlesource.com/75440 Commit-Queue: Karl Wiberg Reviewed-by: Jonas Olsson Reviewed-by: Oskar Sundbom Cr-Commit-Position: refs/heads/master@{#23375} --- .../win/core_audio_utility_win.cc | 2 +- rtc_base/BUILD.gn | 2 +- rtc_base/logging.cc | 92 ++++- rtc_base/logging.h | 358 +++++++++++++++--- rtc_base/system/BUILD.gn | 4 +- rtc_base/system/{no_inline.h => inline.h} | 15 +- 6 files changed, 409 insertions(+), 64 deletions(-) rename rtc_base/system/{no_inline.h => inline.h} (71%) diff --git a/modules/audio_device/win/core_audio_utility_win.cc b/modules/audio_device/win/core_audio_utility_win.cc index bcafccb301..cc9acd7c9e 100644 --- a/modules/audio_device/win/core_audio_utility_win.cc +++ b/modules/audio_device/win/core_audio_utility_win.cc @@ -641,7 +641,7 @@ HRESULT SharedModeInitialize(IAudioClient* client, stream_flags |= AUDCLNT_STREAMFLAGS_EVENTCALLBACK; RTC_DLOG(INFO) << "The stream is initialized to be event driven"; } - RTC_DLOG(INFO) << "stream_flags: 0x" << std::hex << stream_flags; + RTC_DLOG(INFO) << "stream_flags: 0x" << rtc::ToHex(stream_flags); // Initialize the shared mode client for minimal delay. _com_error error = client->Initialize( diff --git a/rtc_base/BUILD.gn b/rtc_base/BUILD.gn index c3fd525e6a..a35a89c043 100644 --- a/rtc_base/BUILD.gn +++ b/rtc_base/BUILD.gn @@ -218,7 +218,7 @@ rtc_source_set("logging") { "logging.cc", "logging.h", ] - deps += [ "system:no_inline" ] + deps += [ "system:inline" ] # logging.h needs the deprecation header while downstream projects are # removing code that depends on logging implementation details. diff --git a/rtc_base/logging.cc b/rtc_base/logging.cc index 8411c21158..0681d8c872 100644 --- a/rtc_base/logging.cc +++ b/rtc_base/logging.cc @@ -33,6 +33,7 @@ static const int kMaxLogLineSize = 1024 - 60; #include #include +#include #include #include #include @@ -237,6 +238,14 @@ LogMessage::~LogMessage() { } } +void LogMessage::AddTag(const char* tag) { +#ifdef WEBRTC_ANDROID + if (!is_noop_) { + tag_ = tag; + } +#endif +} + std::ostream& LogMessage::stream() { return is_noop_ ? GetNoopStream() : print_stream_; } @@ -488,6 +497,87 @@ void LogMessage::FinishPrintStream() { print_stream_ << std::endl; } -////////////////////////////////////////////////////////////////////// +namespace webrtc_logging_impl { +void Log(const LogArgType* fmt, ...) { + va_list args; + va_start(args, fmt); + + LogMetadataErr meta; + const char* tag = nullptr; + switch (*fmt) { + case LogArgType::kLogMetadata: { + meta = {va_arg(args, LogMetadata), ERRCTX_NONE, 0}; + break; + } + case LogArgType::kLogMetadataErr: { + meta = va_arg(args, LogMetadataErr); + break; + } +#ifdef WEBRTC_ANDROID + case LogArgType::kLogMetadataTag: { + const LogMetadataTag tag_meta = va_arg(args, LogMetadataTag); + meta = {{nullptr, 0, tag_meta.severity}, ERRCTX_NONE, 0}; + tag = tag_meta.tag; + break; + } +#endif + default: { + RTC_NOTREACHED(); + va_end(args); + return; + } + } + LogMessage log_message(meta.meta.File(), meta.meta.Line(), + meta.meta.Severity(), meta.err_ctx, meta.err); + if (tag) { + log_message.AddTag(tag); + } + + for (++fmt; *fmt != LogArgType::kEnd; ++fmt) { + switch (*fmt) { + case LogArgType::kInt: + log_message.stream() << va_arg(args, int); + break; + case LogArgType::kLong: + log_message.stream() << va_arg(args, long); + break; + case LogArgType::kLongLong: + log_message.stream() << va_arg(args, long long); + break; + case LogArgType::kUInt: + log_message.stream() << va_arg(args, unsigned); + break; + case LogArgType::kULong: + log_message.stream() << va_arg(args, unsigned long); + break; + case LogArgType::kULongLong: + log_message.stream() << va_arg(args, unsigned long long); + break; + case LogArgType::kDouble: + log_message.stream() << va_arg(args, double); + break; + case LogArgType::kLongDouble: + log_message.stream() << va_arg(args, long double); + break; + case LogArgType::kCharP: + log_message.stream() << va_arg(args, const char*); + break; + case LogArgType::kStdString: + log_message.stream() << *va_arg(args, const std::string*); + break; + case LogArgType::kVoidP: + log_message.stream() << va_arg(args, const void*); + break; + default: + RTC_NOTREACHED(); + va_end(args); + return; + } + } + + va_end(args); +} + +} // namespace webrtc_logging_impl } // namespace rtc diff --git a/rtc_base/logging.h b/rtc_base/logging.h index ff90a81645..f16aca6243 100644 --- a/rtc_base/logging.h +++ b/rtc_base/logging.h @@ -57,7 +57,7 @@ #include "rtc_base/constructormagic.h" #include "rtc_base/deprecation.h" -#include "rtc_base/system/no_inline.h" +#include "rtc_base/system/inline.h" #include "rtc_base/thread_annotations.h" #if !defined(NDEBUG) || defined(DLOG_ALWAYS_ON) @@ -122,6 +122,255 @@ class LogSink { virtual void OnLogMessage(const std::string& message) = 0; }; +namespace webrtc_logging_impl { + +class LogMetadata { + public: + LogMetadata(const char* file, int line, LoggingSeverity severity) + : file_(file), + line_and_sev_(static_cast(line) << 3 | severity) {} + LogMetadata() = default; + + const char* File() const { return file_; } + int Line() const { return line_and_sev_ >> 3; } + LoggingSeverity Severity() const { + return static_cast(line_and_sev_ & 0x7); + } + + private: + const char* file_; + + // Line number and severity, the former in the most significant 29 bits, the + // latter in the least significant 3 bits. (This is an optimization; since + // both numbers are usually compile-time constants, this way we can load them + // both with a single instruction.) + uint32_t line_and_sev_; +}; +static_assert(std::is_trivial::value, ""); + +struct LogMetadataErr { + LogMetadata meta; + LogErrorContext err_ctx; + int err; +}; + +#ifdef WEBRTC_ANDROID +struct LogMetadataTag { + LoggingSeverity severity; + const char* tag; +}; +#endif + +enum class LogArgType : int8_t { + kEnd = 0, + kInt, + kLong, + kLongLong, + kUInt, + kULong, + kULongLong, + kDouble, + kLongDouble, + kCharP, + kStdString, + // TODO(kwiberg): Add absl::StringView. + kVoidP, + kLogMetadata, + kLogMetadataErr, +#ifdef WEBRTC_ANDROID + kLogMetadataTag, +#endif +}; + +// Wrapper for log arguments. Only ever make values of this type with the +// MakeVal() functions. +template +struct Val { + static constexpr LogArgType Type() { return N; } + T GetVal() const { return val; } + T val; +}; + +// TODO(bugs.webrtc.org/9278): Get rid of this specialization when callers +// don't need it anymore. No in-tree caller does, but some external callers +// still do. +template <> +struct Val { + static constexpr LogArgType Type() { return LogArgType::kStdString; } + const std::string* GetVal() const { return &val; } + std::string val; +}; + +inline Val MakeVal(int x) { + return {x}; +} +inline Val MakeVal(long x) { + return {x}; +} +inline Val MakeVal(long long x) { + return {x}; +} +inline Val MakeVal(unsigned int x) { + return {x}; +} +inline Val MakeVal(unsigned long x) { + return {x}; +} +inline Val MakeVal( + unsigned long long x) { + return {x}; +} + +inline Val MakeVal(double x) { + return {x}; +} +inline Val MakeVal(long double x) { + return {x}; +} + +inline Val MakeVal(const char* x) { + return {x}; +} +inline Val MakeVal( + const std::string& x) { + return {&x}; +} +// TODO(kwiberg): Add absl::string_view + +inline Val MakeVal(const void* x) { + return {x}; +} + +inline Val MakeVal( + const LogMetadata& x) { + return {x}; +} +inline Val MakeVal( + const LogMetadataErr& x) { + return {x}; +} + +#ifdef WEBRTC_ANDROID +inline Val MakeVal( + const LogMetadataTag& x) { + return {x}; +} +#endif + +// Handle arbitrary types other than the above by falling back to stringstream. +// TODO(bugs.webrtc.org/9278): Get rid of this overload when callers don't need +// it anymore. No in-tree caller does, but some external callers still do. +template < + typename T, + typename T1 = + typename std::remove_cv::type>::type, + typename std::enable_if< + std::is_class::value && !std::is_same::value && + !std::is_same::value && +#ifdef WEBRTC_ANDROID + !std::is_same::value && +#endif + !std::is_same::value>::type* = nullptr> +Val MakeVal(const T& x) { + std::ostringstream os; // no-presubmit-check TODO(webrtc:8982) + os << x; + return {os.str()}; +} + +void Log(const LogArgType* fmt, ...); + +// Ephemeral type that represents the result of the logging << operator. +template +class LogStreamer; + +// Base case: Before the first << argument. +template <> +class LogStreamer<> final { + public: + template < + typename U, + typename std::enable_if::value>::type* = nullptr> + RTC_FORCE_INLINE LogStreamer()))> operator<<( + U arg) const { + return LogStreamer()))>(MakeVal(arg), + this); + } + + template < + typename U, + typename std::enable_if::value>::type* = nullptr> + RTC_FORCE_INLINE LogStreamer()))> operator<<( + const U& arg) const { + return LogStreamer()))>(MakeVal(arg), + this); + } + + template + RTC_FORCE_INLINE static void Call(const Us&... args) { + static constexpr LogArgType t[] = {Us::Type()..., LogArgType::kEnd}; + Log(t, args.GetVal()...); + } +}; + +// Inductive case: We've already seen at least one << argument. The most recent +// one had type `T`, and the earlier ones had types `Ts`. +template +class LogStreamer final { + public: + RTC_FORCE_INLINE LogStreamer(T arg, const LogStreamer* prior) + : arg_(arg), prior_(prior) {} + + template < + typename U, + typename std::enable_if::value>::type* = nullptr> + RTC_FORCE_INLINE LogStreamer())), T, Ts...> + operator<<(U arg) const { + return LogStreamer())), T, Ts...>( + MakeVal(arg), this); + } + + template < + typename U, + typename std::enable_if::value>::type* = nullptr> + RTC_FORCE_INLINE LogStreamer())), T, Ts...> + operator<<(const U& arg) const { + return LogStreamer())), T, Ts...>( + MakeVal(arg), this); + } + + template + RTC_FORCE_INLINE void Call(const Us&... args) const { + prior_->Call(arg_, args...); + } + + private: + // The most recent argument. + T arg_; + + // Earlier arguments. + const LogStreamer* prior_; +}; + +class LogCall final { + public: + // This can be any binary operator with precedence lower than <<. + template + RTC_FORCE_INLINE void operator&(const LogStreamer& streamer) { + streamer.Call(); + } +}; + +// TODO(bugs.webrtc.org/9278): Remove this once it's no longer used. +struct LogMessageVoidify { + void operator&(std::ostream&) {} // no-presubmit-check TODO(webrtc:8982) +}; + +} // namespace webrtc_logging_impl + +// Direct use of this class is deprecated; please use the logging macros +// instead. +// TODO(bugs.webrtc.org/9278): Move this class to an unnamed namespace in the +// .cc file. class LogMessage { public: LogMessage(const char* file, int line, LoggingSeverity sev); @@ -154,6 +403,8 @@ class LogMessage { ~LogMessage(); + void AddTag(const char* tag); + static bool Loggable(LoggingSeverity sev); // Same as the above, but using a template argument instead of a function @@ -271,39 +522,27 @@ class LogMessage { // Logging Helpers ////////////////////////////////////////////////////////////////////// -// The following non-obvious technique for implementation of a -// conditional log stream was stolen from google3/base/logging.h. - -// This class is used to explicitly ignore values in the conditional -// logging macros. This avoids compiler warnings like "value computed -// is not used" and "statement has no effect". - -class LogMessageVoidify { - public: - LogMessageVoidify() { } - // This has to be an operator with a precedence lower than << but - // higher than ?: - void operator&(std::ostream&) { } -}; - +// DEPRECATED. +// TODO(bugs.webrtc.org/9278): Remove once there are no more users. #define RTC_LOG_SEVERITY_PRECONDITION(sev) \ - !(rtc::LogMessage::Loggable(sev)) \ - ? (void) 0 \ - : rtc::LogMessageVoidify() & + !(rtc::LogMessage::Loggable(sev)) \ + ? static_cast(0) \ + : rtc::webrtc_logging_impl::LogMessageVoidify()& -#define RTC_LOG_SEVERITY_PRECONDITION_C(sev) \ - !(rtc::LogMessage::Loggable()) ? (void)0 : rtc::LogMessageVoidify()& -#define RTC_LOG(sev) \ - RTC_LOG_SEVERITY_PRECONDITION_C(sev) \ - rtc::LogMessage(__FILE__, __LINE__, \ - std::integral_constant()) \ - .stream() +#define RTC_LOG(sev) \ + for (bool do_log = rtc::LogMessage::Loggable(); do_log; \ + do_log = false) \ + rtc::webrtc_logging_impl::LogCall() & \ + rtc::webrtc_logging_impl::LogStreamer<>() \ + << rtc::webrtc_logging_impl::LogMetadata(__FILE__, __LINE__, \ + rtc::sev) -// The _V version is for when a variable is passed in. It doesn't do the -// namespace concatenation. -#define RTC_LOG_V(sev) \ - RTC_LOG_SEVERITY_PRECONDITION(sev) \ - rtc::LogMessage(__FILE__, __LINE__, sev).stream() +// The _V version is for when a variable is passed in. +#define RTC_LOG_V(sev) \ + for (bool do_log = rtc::LogMessage::Loggable(sev); do_log; do_log = false) \ + rtc::webrtc_logging_impl::LogCall() & \ + rtc::webrtc_logging_impl::LogStreamer<>() \ + << rtc::webrtc_logging_impl::LogMetadata(__FILE__, __LINE__, sev) // The _F version prefixes the message with the current function name. #if (defined(__GNUC__) && !defined(NDEBUG)) || defined(WANT_PRETTY_LOG_F) @@ -324,11 +563,14 @@ inline bool LogCheckLevel(LoggingSeverity sev) { return (LogMessage::GetMinLogSeverity() <= sev); } -#define RTC_LOG_E(sev, ctx, err, ...) \ - RTC_LOG_SEVERITY_PRECONDITION_C(sev) \ - rtc::LogMessage(__FILE__, __LINE__, rtc::sev, rtc::ERRCTX_##ctx, err, \ - ##__VA_ARGS__) \ - .stream() +#define RTC_LOG_E(sev, ctx, err) \ + for (bool do_log = rtc::LogMessage::Loggable(); do_log; \ + do_log = false) \ + rtc::webrtc_logging_impl::LogCall() & \ + rtc::webrtc_logging_impl::LogStreamer<>() \ + << rtc::webrtc_logging_impl::LogMetadataErr { \ + {__FILE__, __LINE__, rtc::sev}, rtc::ERRCTX_##ctx, (err) \ + } #define RTC_LOG_T(sev) RTC_LOG(sev) << this << ": " @@ -340,8 +582,7 @@ inline bool LogCheckLevel(LoggingSeverity sev) { #if defined(WEBRTC_WIN) #define RTC_LOG_GLE_EX(sev, err) \ RTC_LOG_E(sev, HRESULT, err) -#define RTC_LOG_GLE(sev) \ - RTC_LOG_GLE_EX(sev, GetLastError()) +#define RTC_LOG_GLE(sev) RTC_LOG_GLE_EX(sev, static_cast(GetLastError())) #define RTC_LOG_ERR_EX(sev, err) \ RTC_LOG_GLE_EX(sev, err) #define RTC_LOG_ERR(sev) \ @@ -358,20 +599,27 @@ inline bool LogCheckLevel(LoggingSeverity sev) { RTC_LOG_ERRNO(sev) #endif // WEBRTC_WIN -#if defined(WEBRTC_ANDROID) -namespace internal { -// Inline adapters provided for backwards compatibility for downstream projects. +#ifdef WEBRTC_ANDROID + +namespace webrtc_logging_impl { +// TODO(kwiberg): Replace these with absl::string_view. inline const char* AdaptString(const char* str) { return str; } inline const char* AdaptString(const std::string& str) { return str.c_str(); } -} // namespace internal -#define RTC_LOG_TAG(sev, tag) \ - RTC_LOG_SEVERITY_PRECONDITION(sev) \ - rtc::LogMessage(nullptr, 0, sev, rtc::internal::AdaptString(tag)).stream() +} // namespace webrtc_logging_impl + +#define RTC_LOG_TAG(sev, tag) \ + for (bool do_log = rtc::LogMessage::Loggable(sev); do_log; do_log = false) \ + rtc::webrtc_logging_impl::LogCall() & \ + rtc::webrtc_logging_impl::LogStreamer<>() \ + << rtc::webrtc_logging_impl::LogMetadataTag { \ + sev, rtc::webrtc_logging_impl::AdaptString(tag) \ + } + #else + // DEPRECATED. This macro is only intended for Android. -#define RTC_LOG_TAG(sev, tag) \ - RTC_LOG_SEVERITY_PRECONDITION(sev) \ - rtc::LogMessage(nullptr, 0, sev).stream() +#define RTC_LOG_TAG(sev, tag) RTC_LOG_V(sev) + #endif // The RTC_DLOG macros are equivalent to their RTC_LOG counterparts except that @@ -381,14 +629,12 @@ inline const char* AdaptString(const std::string& str) { return str.c_str(); } #define RTC_DLOG_V(sev) RTC_LOG_V(sev) #define RTC_DLOG_F(sev) RTC_LOG_F(sev) #else -#define RTC_DLOG_EAT_STREAM_PARAMS(sev) \ - (true ? true : ((void)(sev), true)) \ - ? static_cast(0) \ - : rtc::LogMessageVoidify() & \ - rtc::LogMessage(__FILE__, __LINE__, sev).stream() -#define RTC_DLOG(sev) RTC_DLOG_EAT_STREAM_PARAMS(rtc::sev) -#define RTC_DLOG_V(sev) RTC_DLOG_EAT_STREAM_PARAMS(sev) -#define RTC_DLOG_F(sev) RTC_DLOG_EAT_STREAM_PARAMS(rtc::sev) +#define RTC_DLOG_EAT_STREAM_PARAMS() \ + while (false) \ + rtc::webrtc_logging_impl::LogStreamer<>() +#define RTC_DLOG(sev) RTC_DLOG_EAT_STREAM_PARAMS() +#define RTC_DLOG_V(sev) RTC_DLOG_EAT_STREAM_PARAMS() +#define RTC_DLOG_F(sev) RTC_DLOG_EAT_STREAM_PARAMS() #endif } // namespace rtc diff --git a/rtc_base/system/BUILD.gn b/rtc_base/system/BUILD.gn index 02ffaa79e9..9d3fa2c98a 100644 --- a/rtc_base/system/BUILD.gn +++ b/rtc_base/system/BUILD.gn @@ -49,9 +49,9 @@ rtc_source_set("ignore_warnings") { ] } -rtc_source_set("no_inline") { +rtc_source_set("inline") { sources = [ - "no_inline.h", + "inline.h", ] } diff --git a/rtc_base/system/no_inline.h b/rtc_base/system/inline.h similarity index 71% rename from rtc_base/system/no_inline.h rename to rtc_base/system/inline.h index c309e851b1..f585d34ded 100644 --- a/rtc_base/system/no_inline.h +++ b/rtc_base/system/inline.h @@ -8,15 +8,24 @@ * be found in the AUTHORS file in the root of the source tree. */ -#ifndef RTC_BASE_SYSTEM_NO_INLINE_H_ -#define RTC_BASE_SYSTEM_NO_INLINE_H_ +#ifndef RTC_BASE_SYSTEM_INLINE_H_ +#define RTC_BASE_SYSTEM_INLINE_H_ #if defined(_MSC_VER) + +#define RTC_FORCE_INLINE __forceinline #define RTC_NO_INLINE __declspec(noinline) + #elif defined(__GNUC__) + +#define RTC_FORCE_INLINE __attribute__((__always_inline__)) #define RTC_NO_INLINE __attribute__((__noinline__)) + #else + +#define RTC_FORCE_INLINE #define RTC_NO_INLINE + #endif -#endif // RTC_BASE_SYSTEM_NO_INLINE_H_ +#endif // RTC_BASE_SYSTEM_INLINE_H_