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 <kwiberg@webrtc.org>
Reviewed-by: Jonas Olsson <jonasolsson@webrtc.org>
Reviewed-by: Oskar Sundbom <ossu@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#23375}
This commit is contained in:
Karl Wiberg 2018-05-23 23:20:38 +02:00 committed by Commit Bot
parent 223cc4b0e7
commit cefc46517e
6 changed files with 409 additions and 64 deletions

View File

@ -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(

View File

@ -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.

View File

@ -33,6 +33,7 @@ static const int kMaxLogLineSize = 1024 - 60;
#include <limits.h>
#include <algorithm>
#include <cstdarg>
#include <iomanip>
#include <ostream>
#include <vector>
@ -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

View File

@ -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<uint32_t>(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<LoggingSeverity>(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<LogMetadata>::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 <LogArgType N, typename T>
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<LogArgType::kStdString, std::string> {
static constexpr LogArgType Type() { return LogArgType::kStdString; }
const std::string* GetVal() const { return &val; }
std::string val;
};
inline Val<LogArgType::kInt, int> MakeVal(int x) {
return {x};
}
inline Val<LogArgType::kLong, long> MakeVal(long x) {
return {x};
}
inline Val<LogArgType::kLongLong, long long> MakeVal(long long x) {
return {x};
}
inline Val<LogArgType::kUInt, unsigned int> MakeVal(unsigned int x) {
return {x};
}
inline Val<LogArgType::kULong, unsigned long> MakeVal(unsigned long x) {
return {x};
}
inline Val<LogArgType::kULongLong, unsigned long long> MakeVal(
unsigned long long x) {
return {x};
}
inline Val<LogArgType::kDouble, double> MakeVal(double x) {
return {x};
}
inline Val<LogArgType::kLongDouble, long double> MakeVal(long double x) {
return {x};
}
inline Val<LogArgType::kCharP, const char*> MakeVal(const char* x) {
return {x};
}
inline Val<LogArgType::kStdString, const std::string*> MakeVal(
const std::string& x) {
return {&x};
}
// TODO(kwiberg): Add absl::string_view
inline Val<LogArgType::kVoidP, const void*> MakeVal(const void* x) {
return {x};
}
inline Val<LogArgType::kLogMetadata, LogMetadata> MakeVal(
const LogMetadata& x) {
return {x};
}
inline Val<LogArgType::kLogMetadataErr, LogMetadataErr> MakeVal(
const LogMetadataErr& x) {
return {x};
}
#ifdef WEBRTC_ANDROID
inline Val<LogArgType::kLogMetadataTag, LogMetadataTag> 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<typename std::remove_reference<T>::type>::type,
typename std::enable_if<
std::is_class<T1>::value && !std::is_same<T1, std::string>::value &&
!std::is_same<T1, LogMetadata>::value &&
#ifdef WEBRTC_ANDROID
!std::is_same<T1, LogMetadataTag>::value &&
#endif
!std::is_same<T1, LogMetadataErr>::value>::type* = nullptr>
Val<LogArgType::kStdString, std::string> 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 <typename... Ts>
class LogStreamer;
// Base case: Before the first << argument.
template <>
class LogStreamer<> final {
public:
template <
typename U,
typename std::enable_if<std::is_arithmetic<U>::value>::type* = nullptr>
RTC_FORCE_INLINE LogStreamer<decltype(MakeVal(std::declval<U>()))> operator<<(
U arg) const {
return LogStreamer<decltype(MakeVal(std::declval<U>()))>(MakeVal(arg),
this);
}
template <
typename U,
typename std::enable_if<!std::is_arithmetic<U>::value>::type* = nullptr>
RTC_FORCE_INLINE LogStreamer<decltype(MakeVal(std::declval<U>()))> operator<<(
const U& arg) const {
return LogStreamer<decltype(MakeVal(std::declval<U>()))>(MakeVal(arg),
this);
}
template <typename... Us>
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 <typename T, typename... Ts>
class LogStreamer<T, Ts...> final {
public:
RTC_FORCE_INLINE LogStreamer(T arg, const LogStreamer<Ts...>* prior)
: arg_(arg), prior_(prior) {}
template <
typename U,
typename std::enable_if<std::is_arithmetic<U>::value>::type* = nullptr>
RTC_FORCE_INLINE LogStreamer<decltype(MakeVal(std::declval<U>())), T, Ts...>
operator<<(U arg) const {
return LogStreamer<decltype(MakeVal(std::declval<U>())), T, Ts...>(
MakeVal(arg), this);
}
template <
typename U,
typename std::enable_if<!std::is_arithmetic<U>::value>::type* = nullptr>
RTC_FORCE_INLINE LogStreamer<decltype(MakeVal(std::declval<U>())), T, Ts...>
operator<<(const U& arg) const {
return LogStreamer<decltype(MakeVal(std::declval<U>())), T, Ts...>(
MakeVal(arg), this);
}
template <typename... Us>
RTC_FORCE_INLINE void Call(const Us&... args) const {
prior_->Call(arg_, args...);
}
private:
// The most recent argument.
T arg_;
// Earlier arguments.
const LogStreamer<Ts...>* prior_;
};
class LogCall final {
public:
// This can be any binary operator with precedence lower than <<.
template <typename... Ts>
RTC_FORCE_INLINE void operator&(const LogStreamer<Ts...>& 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() &
? static_cast<void>(0) \
: rtc::webrtc_logging_impl::LogMessageVoidify()&
#define RTC_LOG_SEVERITY_PRECONDITION_C(sev) \
!(rtc::LogMessage::Loggable<rtc::sev>()) ? (void)0 : rtc::LogMessageVoidify()&
#define RTC_LOG(sev) \
RTC_LOG_SEVERITY_PRECONDITION_C(sev) \
rtc::LogMessage(__FILE__, __LINE__, \
std::integral_constant<rtc::LoggingSeverity, rtc::sev>()) \
.stream()
for (bool do_log = rtc::LogMessage::Loggable<rtc::sev>(); 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.
// The _V version is for when a variable is passed in.
#define RTC_LOG_V(sev) \
RTC_LOG_SEVERITY_PRECONDITION(sev) \
rtc::LogMessage(__FILE__, __LINE__, sev).stream()
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<rtc::sev>(); 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<int>(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
} // namespace webrtc_logging_impl
#define RTC_LOG_TAG(sev, tag) \
RTC_LOG_SEVERITY_PRECONDITION(sev) \
rtc::LogMessage(nullptr, 0, sev, rtc::internal::AdaptString(tag)).stream()
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<void>(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

View File

@ -49,9 +49,9 @@ rtc_source_set("ignore_warnings") {
]
}
rtc_source_set("no_inline") {
rtc_source_set("inline") {
sources = [
"no_inline.h",
"inline.h",
]
}

View File

@ -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_