diff options
Diffstat (limited to 'absl/log')
28 files changed, 1219 insertions, 724 deletions
diff --git a/absl/log/BUILD.bazel b/absl/log/BUILD.bazel index 40e87cc9..b13cf4d4 100644 --- a/absl/log/BUILD.bazel +++ b/absl/log/BUILD.bazel @@ -243,9 +243,6 @@ cc_library( hdrs = ["absl_vlog_is_on.h"], copts = ABSL_DEFAULT_COPTS, linkopts = ABSL_DEFAULT_LINKOPTS, - visibility = [ - "//absl/log:__subpackages__", - ], deps = [ "//absl/base:config", "//absl/base:core_headers", @@ -259,9 +256,6 @@ cc_library( hdrs = ["vlog_is_on.h"], copts = ABSL_DEFAULT_COPTS, linkopts = ABSL_DEFAULT_LINKOPTS, - visibility = [ - "//absl/log:__subpackages__", - ], deps = [ ":absl_vlog_is_on", ], @@ -295,6 +289,7 @@ cc_test( cc_test( name = "absl_check_test", size = "small", + timeout = "moderate", srcs = ["absl_check_test.cc"], copts = ABSL_TEST_COPTS, linkopts = ABSL_DEFAULT_LINKOPTS, @@ -328,6 +323,7 @@ cc_test( cc_test( name = "check_test", size = "small", + timeout = "moderate", srcs = ["check_test.cc"], copts = ABSL_TEST_COPTS, linkopts = ABSL_DEFAULT_LINKOPTS, @@ -361,6 +357,8 @@ cc_library( "//absl/base:core_headers", "//absl/log/internal:test_helpers", "//absl/status", + "//absl/strings", + "//absl/strings:string_view", "@com_google_googletest//:gtest", ], ) @@ -450,6 +448,7 @@ cc_library( "//absl/log:globals", "//absl/log:log_entry", "//absl/log:scoped_mock_log", + "//absl/log/internal:globals", "//absl/log/internal:test_actions", "//absl/log/internal:test_helpers", "//absl/log/internal:test_matchers", @@ -667,6 +666,7 @@ cc_test( ":log_entry", ":log_sink", ":log_sink_registry", + ":vlog_is_on", "//absl/base:core_headers", "//absl/base:log_severity", "//absl/flags:flag", diff --git a/absl/log/CMakeLists.txt b/absl/log/CMakeLists.txt index a7d8b690..43844651 100644 --- a/absl/log/CMakeLists.txt +++ b/absl/log/CMakeLists.txt @@ -290,6 +290,7 @@ absl_cc_library( LINKOPTS ${ABSL_DEFAULT_LINKOPTS} DEPS + absl::core_headers absl::log_internal_message absl::log_internal_nullstream absl::log_severity @@ -788,6 +789,8 @@ absl_cc_test( absl::core_headers absl::log_internal_test_helpers absl::status + absl::strings + absl::string_view GTest::gmock_main ) @@ -807,6 +810,7 @@ absl_cc_test( absl::log_entry absl::log_globals absl::log_severity + absl::log_internal_globals absl::log_internal_test_actions absl::log_internal_test_helpers absl::log_internal_test_matchers @@ -830,6 +834,8 @@ absl_cc_test( absl::core_headers absl::log_internal_test_helpers absl::status + absl::strings + absl::string_view GTest::gmock_main ) diff --git a/absl/log/absl_log_basic_test.cc b/absl/log/absl_log_basic_test.cc index 3a4b83c1..7378f5a8 100644 --- a/absl/log/absl_log_basic_test.cc +++ b/absl/log/absl_log_basic_test.cc @@ -16,6 +16,7 @@ #include "absl/log/absl_log.h" #define ABSL_TEST_LOG ABSL_LOG +#define ABSL_TEST_DLOG ABSL_DLOG #include "gtest/gtest.h" #include "absl/log/log_basic_test_impl.inc" diff --git a/absl/log/absl_vlog_is_on.h b/absl/log/absl_vlog_is_on.h index 29096b48..6bf6c413 100644 --- a/absl/log/absl_vlog_is_on.h +++ b/absl/log/absl_vlog_is_on.h @@ -46,12 +46,12 @@ // Files which do not match any pattern in `--vmodule` use the value of `--v` as // their effective verbosity level. The default is 0. // -// SetVLOGLevel helper function is provided to do limited dynamic control over +// SetVLogLevel helper function is provided to do limited dynamic control over // V-logging by appending to `--vmodule`. Because these go at the beginning of // the list, they take priority over any globs previously added. // // Resetting --vmodule will override all previous modifications to `--vmodule`, -// including via SetVLOGLevel. +// including via SetVLogLevel. #ifndef ABSL_LOG_ABSL_VLOG_IS_ON_H_ #define ABSL_LOG_ABSL_VLOG_IS_ON_H_ @@ -77,7 +77,7 @@ // Each ABSL_VLOG_IS_ON call site gets its own VLogSite that registers with the // global linked list of sites to asynchronously update its verbosity level on // changes to --v or --vmodule. The verbosity can also be set by manually -// calling SetVLOGLevel. +// calling SetVLogLevel. // // ABSL_VLOG_IS_ON is not async signal safe, but it is guaranteed not to // allocate new memory. diff --git a/absl/log/check_test_impl.inc b/absl/log/check_test_impl.inc index d5c0aee4..64318108 100644 --- a/absl/log/check_test_impl.inc +++ b/absl/log/check_test_impl.inc @@ -31,6 +31,8 @@ #include "absl/base/config.h" #include "absl/log/internal/test_helpers.h" #include "absl/status/status.h" +#include "absl/strings/string_view.h" +#include "absl/strings/substitute.h" // NOLINTBEGIN(misc-definitions-in-headers) @@ -521,6 +523,162 @@ TEST(CHECKDeathTest, TestUserDefinedStreaming) { "Check failed: v1 == v2 (ComparableType{1} vs. ComparableType{2})")); } +// A type that can be printed using AbslStringify. +struct StringifiableType { + int x = 0; + explicit StringifiableType(int x) : x(x) {} + friend bool operator==(const StringifiableType& lhs, + const StringifiableType& rhs) { + return lhs.x == rhs.x; + } + friend bool operator!=(const StringifiableType& lhs, + const StringifiableType& rhs) { + return lhs.x != rhs.x; + } + friend bool operator<(const StringifiableType& lhs, + const StringifiableType& rhs) { + return lhs.x < rhs.x; + } + friend bool operator>(const StringifiableType& lhs, + const StringifiableType& rhs) { + return lhs.x > rhs.x; + } + friend bool operator<=(const StringifiableType& lhs, + const StringifiableType& rhs) { + return lhs.x <= rhs.x; + } + friend bool operator>=(const StringifiableType& lhs, + const StringifiableType& rhs) { + return lhs.x >= rhs.x; + } + template <typename Sink> + friend void AbslStringify(Sink& sink, const StringifiableType& obj) { + absl::Format(&sink, "StringifiableType{%d}", obj.x); + } + + // Make sure no unintended copy happens. + StringifiableType(const StringifiableType&) = delete; +}; + +TEST(CHECKTest, TestUserDefinedAbslStringify) { + const StringifiableType v1(1); + const StringifiableType v2(2); + + ABSL_TEST_CHECK_EQ(v1, v1); + ABSL_TEST_CHECK_NE(v1, v2); + ABSL_TEST_CHECK_LT(v1, v2); + ABSL_TEST_CHECK_LE(v1, v2); + ABSL_TEST_CHECK_GT(v2, v1); + ABSL_TEST_CHECK_GE(v2, v1); +} + +TEST(CHECKDeathTest, TestUserDefinedAbslStringify) { + const StringifiableType v1(1); + const StringifiableType v2(2); + + // Returns a matcher for the expected check failure message when comparing two + // values. + auto expected_output = [](int lhs, absl::string_view condition, int rhs) { + return HasSubstr( + absl::Substitute("Check failed: v$0 $1 v$2 (StringifiableType{$0} vs. " + "StringifiableType{$2})", + lhs, condition, rhs)); + }; + // Test comparisons where the check fails. + EXPECT_DEATH(ABSL_TEST_CHECK_EQ(v1, v2), expected_output(1, "==", 2)); + EXPECT_DEATH(ABSL_TEST_CHECK_NE(v1, v1), expected_output(1, "!=", 1)); + EXPECT_DEATH(ABSL_TEST_CHECK_LT(v2, v1), expected_output(2, "<", 1)); + EXPECT_DEATH(ABSL_TEST_CHECK_LE(v2, v1), expected_output(2, "<=", 1)); + EXPECT_DEATH(ABSL_TEST_CHECK_GT(v1, v2), expected_output(1, ">", 2)); + EXPECT_DEATH(ABSL_TEST_CHECK_GE(v1, v2), expected_output(1, ">=", 2)); +} + +// A type that can be printed using both AbslStringify and operator<<. +struct StringifiableStreamableType { + int x = 0; + explicit StringifiableStreamableType(int x) : x(x) {} + + friend bool operator==(const StringifiableStreamableType& lhs, + const StringifiableStreamableType& rhs) { + return lhs.x == rhs.x; + } + friend bool operator!=(const StringifiableStreamableType& lhs, + const StringifiableStreamableType& rhs) { + return lhs.x != rhs.x; + } + template <typename Sink> + friend void AbslStringify(Sink& sink, + const StringifiableStreamableType& obj) { + absl::Format(&sink, "Strigified{%d}", obj.x); + } + friend std::ostream& operator<<(std::ostream& out, + const StringifiableStreamableType& obj) { + return out << "Streamed{" << obj.x << "}"; + } + + // Avoid unintentional copy. + StringifiableStreamableType(const StringifiableStreamableType&) = delete; +}; + +TEST(CHECKDeathTest, TestStreamingPreferredOverAbslStringify) { + StringifiableStreamableType v1(1); + StringifiableStreamableType v2(2); + + EXPECT_DEATH( + ABSL_TEST_CHECK_EQ(v1, v2), + HasSubstr("Check failed: v1 == v2 (Streamed{1} vs. Streamed{2})")); +} + +// A type whose pointer can be passed to AbslStringify. +struct PointerIsStringifiable {}; +template <typename Sink> +void AbslStringify(Sink& sink, const PointerIsStringifiable* var) { + sink.Append("PointerIsStringifiable"); +} + +// Verifies that a pointer is printed as a number despite having AbslStringify +// defined. Users may implement AbslStringify that dereferences the pointer, and +// doing so as part of DCHECK would not be good. +TEST(CHECKDeathTest, TestPointerPrintedAsNumberDespiteAbslStringify) { + const auto* p = reinterpret_cast<const PointerIsStringifiable*>(0x1234); + +#ifdef _MSC_VER + EXPECT_DEATH( + ABSL_TEST_CHECK_EQ(p, nullptr), + HasSubstr("Check failed: p == nullptr (0000000000001234 vs. (null))")); +#else // _MSC_VER + EXPECT_DEATH(ABSL_TEST_CHECK_EQ(p, nullptr), + HasSubstr("Check failed: p == nullptr (0x1234 vs. (null))")); +#endif // _MSC_VER +} + +// An uncopyable object with operator<<. +struct Uncopyable { + int x; + explicit Uncopyable(int x) : x(x) {} + Uncopyable(const Uncopyable&) = delete; + friend bool operator==(const Uncopyable& lhs, const Uncopyable& rhs) { + return lhs.x == rhs.x; + } + friend bool operator!=(const Uncopyable& lhs, const Uncopyable& rhs) { + return lhs.x != rhs.x; + } + friend std::ostream& operator<<(std::ostream& os, const Uncopyable& obj) { + return os << "Uncopyable{" << obj.x << "}"; + } +}; + +// Test that an uncopyable object can be used. +// Will catch us if implementation has an unintended copy. +TEST(CHECKDeathTest, TestUncopyable) { + const Uncopyable v1(1); + const Uncopyable v2(2); + + EXPECT_DEATH( + ABSL_TEST_CHECK_EQ(v1, v2), + HasSubstr("Check failed: v1 == v2 (Uncopyable{1} vs. Uncopyable{2})")); +} + } // namespace absl_log_internal // NOLINTEND(misc-definitions-in-headers) diff --git a/absl/log/die_if_null.h b/absl/log/die_if_null.h index 127a9ac8..f773aa85 100644 --- a/absl/log/die_if_null.h +++ b/absl/log/die_if_null.h @@ -55,7 +55,7 @@ namespace log_internal { // `line` location. Called when `ABSL_DIE_IF_NULL` fails. Calling this function // generates less code than its implementation would if inlined, for a slight // code size reduction each time `ABSL_DIE_IF_NULL` is called. -ABSL_ATTRIBUTE_NORETURN ABSL_ATTRIBUTE_NOINLINE void DieBecauseNull( +[[noreturn]] ABSL_ATTRIBUTE_NOINLINE void DieBecauseNull( const char* file, int line, const char* exprtext); // Helper for `ABSL_DIE_IF_NULL`. diff --git a/absl/log/globals.h b/absl/log/globals.h index b36e47e6..4feec407 100644 --- a/absl/log/globals.h +++ b/absl/log/globals.h @@ -140,7 +140,7 @@ void ClearLogBacktraceLocation(); // // This option tells the logging library that every logged message // should include the prefix (severity, date, time, PID, etc.) - +// // ShouldPrependLogPrefix() // // Returns the value of the Prepend Log Prefix option. @@ -154,25 +154,38 @@ ABSL_MUST_USE_RESULT bool ShouldPrependLogPrefix(); void EnableLogPrefix(bool on_off); //------------------------------------------------------------------------------ -// Set Global VLOG Level +// `VLOG` Configuration //------------------------------------------------------------------------------ // -// Sets the global `(ABSL_)VLOG(_IS_ON)` level to `log_level`. This level is -// applied to any sites whose filename doesn't match any `module_pattern`. -// Returns the prior value. -inline int SetGlobalVLogLevel(int log_level) { - return absl::log_internal::UpdateGlobalVLogLevel(log_level); +// These methods set the `(ABSL_)VLOG(_IS_ON)` threshold. They allow +// programmatic control of the thresholds set by the --v and --vmodule flags. +// +// Only `VLOG`s with a severity level LESS THAN OR EQUAL TO the threshold will +// be evaluated. +// +// For example, if the threshold is 2, then: +// +// VLOG(2) << "This message will be logged."; +// VLOG(3) << "This message will NOT be logged."; +// +// The default threshold is 0. Since `VLOG` levels must not be negative, a +// negative threshold value will turn off all VLOGs. + +// SetGlobalVLogLevel() +// +// Sets the global `VLOG` level to threshold. Returns the previous global +// threshold. +inline int SetGlobalVLogLevel(int threshold) { + return absl::log_internal::UpdateGlobalVLogLevel(threshold); } -//------------------------------------------------------------------------------ -// Set VLOG Level -//------------------------------------------------------------------------------ +// SetVLogLevel() // -// Sets `(ABSL_)VLOG(_IS_ON)` level for `module_pattern` to `log_level`. This -// allows programmatic control of what is normally set by the --vmodule flag. -// Returns the level that previously applied to `module_pattern`. -inline int SetVLogLevel(absl::string_view module_pattern, int log_level) { - return absl::log_internal::PrependVModule(module_pattern, log_level); +// Sets the `VLOG` threshold for all files that match `module_pattern`, +// overwriting any prior value. Files that don't match aren't affected. +// Returns the threshold that previously applied to `module_pattern`. +inline int SetVLogLevel(absl::string_view module_pattern, int threshold) { + return absl::log_internal::PrependVModule(module_pattern, threshold); } //------------------------------------------------------------------------------ diff --git a/absl/log/internal/BUILD.bazel b/absl/log/internal/BUILD.bazel index 1be13499..2dbf337a 100644 --- a/absl/log/internal/BUILD.bazel +++ b/absl/log/internal/BUILD.bazel @@ -266,6 +266,7 @@ cc_library( deps = [ ":log_message", ":nullstream", + "//absl/base:core_headers", "//absl/base:log_severity", ], ) @@ -384,7 +385,9 @@ cc_library( hdrs = ["vlog_config.h"], copts = ABSL_DEFAULT_COPTS, linkopts = ABSL_DEFAULT_LINKOPTS, - visibility = ["//absl/log:__subpackages__"], + visibility = [ + "//absl/log:__subpackages__", + ], deps = [ "//absl/base", "//absl/base:config", @@ -400,7 +403,7 @@ cc_library( cc_binary( name = "vlog_config_benchmark", - testonly = 1, + testonly = True, srcs = ["vlog_config_benchmark.cc"], copts = ABSL_TEST_COPTS, linkopts = ABSL_DEFAULT_LINKOPTS, diff --git a/absl/log/internal/check_op.cc b/absl/log/internal/check_op.cc index f4b67647..23c4a3b2 100644 --- a/absl/log/internal/check_op.cc +++ b/absl/log/internal/check_op.cc @@ -16,6 +16,10 @@ #include <string.h> +#include <ostream> + +#include "absl/strings/string_view.h" + #ifdef _MSC_VER #define strcasecmp _stricmp #else @@ -113,6 +117,22 @@ DEFINE_CHECK_STROP_IMPL(CHECK_STRCASEEQ, strcasecmp, true) DEFINE_CHECK_STROP_IMPL(CHECK_STRCASENE, strcasecmp, false) #undef DEFINE_CHECK_STROP_IMPL +namespace detect_specialization { + +StringifySink::StringifySink(std::ostream& os) : os_(os) {} + +void StringifySink::Append(absl::string_view text) { os_ << text; } + +void StringifySink::Append(size_t length, char ch) { + for (size_t i = 0; i < length; ++i) os_.put(ch); +} + +void AbslFormatFlush(StringifySink* sink, absl::string_view text) { + sink->Append(text); +} + +} // namespace detect_specialization + } // namespace log_internal ABSL_NAMESPACE_END } // namespace absl diff --git a/absl/log/internal/check_op.h b/absl/log/internal/check_op.h index 11f0f407..21592207 100644 --- a/absl/log/internal/check_op.h +++ b/absl/log/internal/check_op.h @@ -24,9 +24,11 @@ #include <stdint.h> +#include <cstddef> #include <ostream> #include <sstream> #include <string> +#include <type_traits> #include <utility> #include "absl/base/attributes.h" @@ -35,6 +37,8 @@ #include "absl/log/internal/nullguard.h" #include "absl/log/internal/nullstream.h" #include "absl/log/internal/strip.h" +#include "absl/strings/has_absl_stringify.h" +#include "absl/strings/string_view.h" // `ABSL_LOG_INTERNAL_STRIP_STRING_LITERAL` wraps string literals that // should be stripped when `ABSL_MIN_LOG_LEVEL` exceeds `kFatal`. @@ -58,13 +62,13 @@ #endif #define ABSL_LOG_INTERNAL_CHECK_OP(name, op, val1, val1_text, val2, val2_text) \ - while ( \ - ::std::string* absl_log_internal_check_op_result ABSL_ATTRIBUTE_UNUSED = \ - ::absl::log_internal::name##Impl( \ - ::absl::log_internal::GetReferenceableValue(val1), \ - ::absl::log_internal::GetReferenceableValue(val2), \ - ABSL_LOG_INTERNAL_STRIP_STRING_LITERAL(val1_text \ - " " #op " " val2_text))) \ + while (::std::string* absl_log_internal_check_op_result \ + ABSL_LOG_INTERNAL_ATTRIBUTE_UNUSED_IF_STRIP_LOG = \ + ::absl::log_internal::name##Impl( \ + ::absl::log_internal::GetReferenceableValue(val1), \ + ::absl::log_internal::GetReferenceableValue(val2), \ + ABSL_LOG_INTERNAL_STRIP_STRING_LITERAL( \ + val1_text " " #op " " val2_text))) \ ABSL_LOG_INTERNAL_CONDITION_FATAL(STATELESS, true) \ ABSL_LOG_INTERNAL_CHECK(*absl_log_internal_check_op_result).InternalStream() #define ABSL_LOG_INTERNAL_QCHECK_OP(name, op, val1, val1_text, val2, \ @@ -287,6 +291,44 @@ decltype(detect_specialization::operator<<(std::declval<std::ostream&>(), std::declval<const T&>())) Detect(char); +// A sink for AbslStringify which redirects everything to a std::ostream. +class StringifySink { + public: + explicit StringifySink(std::ostream& os ABSL_ATTRIBUTE_LIFETIME_BOUND); + + void Append(absl::string_view text); + void Append(size_t length, char ch); + friend void AbslFormatFlush(StringifySink* sink, absl::string_view text); + + private: + std::ostream& os_; +}; + +// Wraps a type implementing AbslStringify, and implements operator<<. +template <typename T> +class StringifyToStreamWrapper { + public: + explicit StringifyToStreamWrapper(const T& v ABSL_ATTRIBUTE_LIFETIME_BOUND) + : v_(v) {} + + friend std::ostream& operator<<(std::ostream& os, + const StringifyToStreamWrapper& wrapper) { + StringifySink sink(os); + AbslStringify(sink, wrapper.v_); + return os; + } + + private: + const T& v_; +}; + +// This overload triggers when T implements AbslStringify. +// StringifyToStreamWrapper is used to allow MakeCheckOpString to use +// operator<<. +template <typename T> +std::enable_if_t<HasAbslStringify<T>::value, + StringifyToStreamWrapper<T>> +Detect(...); // Ellipsis has lowest preference when int passed. } // namespace detect_specialization template <typename T> @@ -342,20 +384,20 @@ ABSL_LOG_INTERNAL_DEFINE_MAKE_CHECK_OP_STRING_EXTERN(const void*); // `(int, int)` override works around the issue that the compiler will not // instantiate the template version of the function on values of unnamed enum // type. -#define ABSL_LOG_INTERNAL_CHECK_OP_IMPL(name, op) \ - template <typename T1, typename T2> \ - inline constexpr ::std::string* name##Impl(const T1& v1, const T2& v2, \ - const char* exprtext) { \ - using U1 = CheckOpStreamType<T1>; \ - using U2 = CheckOpStreamType<T2>; \ - return ABSL_PREDICT_TRUE(v1 op v2) \ - ? nullptr \ - : ABSL_LOG_INTERNAL_CHECK_OP_IMPL_RESULT(U1, U2, v1, v2, \ - exprtext); \ - } \ - inline constexpr ::std::string* name##Impl(int v1, int v2, \ - const char* exprtext) { \ - return name##Impl<int, int>(v1, v2, exprtext); \ +#define ABSL_LOG_INTERNAL_CHECK_OP_IMPL(name, op) \ + template <typename T1, typename T2> \ + inline constexpr ::std::string* name##Impl(const T1& v1, const T2& v2, \ + const char* exprtext) { \ + using U1 = CheckOpStreamType<T1>; \ + using U2 = CheckOpStreamType<T2>; \ + return ABSL_PREDICT_TRUE(v1 op v2) \ + ? nullptr \ + : ABSL_LOG_INTERNAL_CHECK_OP_IMPL_RESULT(U1, U2, U1(v1), \ + U2(v2), exprtext); \ + } \ + inline constexpr ::std::string* name##Impl(int v1, int v2, \ + const char* exprtext) { \ + return name##Impl<int, int>(v1, v2, exprtext); \ } ABSL_LOG_INTERNAL_CHECK_OP_IMPL(Check_EQ, ==) diff --git a/absl/log/internal/conditions.h b/absl/log/internal/conditions.h index 645f3c23..9dc15db4 100644 --- a/absl/log/internal/conditions.h +++ b/absl/log/internal/conditions.h @@ -230,8 +230,8 @@ class LogEveryNSecState final { // Helper routines to abort the application quietly -ABSL_ATTRIBUTE_NORETURN inline void AbortQuietly() { abort(); } -ABSL_ATTRIBUTE_NORETURN inline void ExitQuietly() { _exit(1); } +[[noreturn]] inline void AbortQuietly() { abort(); } +[[noreturn]] inline void ExitQuietly() { _exit(1); } } // namespace log_internal ABSL_NAMESPACE_END } // namespace absl diff --git a/absl/log/internal/log_impl.h b/absl/log/internal/log_impl.h index 99de6dbb..a67f2f31 100644 --- a/absl/log/internal/log_impl.h +++ b/absl/log/internal/log_impl.h @@ -35,14 +35,14 @@ #ifndef NDEBUG #define ABSL_LOG_INTERNAL_DLOG_IMPL(severity) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATELESS, true) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #else #define ABSL_LOG_INTERNAL_DLOG_IMPL(severity) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATELESS, false) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #endif -// The `switch` ensures that this expansion is the begnning of a statement (as +// The `switch` ensures that this expansion is the beginning of a statement (as // opposed to an expression). The use of both `case 0` and `default` is to // suppress a compiler warning. #define ABSL_LOG_INTERNAL_VLOG_IMPL(verbose_level) \ @@ -58,7 +58,7 @@ switch (const int absl_logging_internal_verbose_level = (verbose_level)) \ case 0: \ default: \ - ABSL_LOG_INTERNAL_LOG_IF_IMPL( \ + ABSL_LOG_INTERNAL_DLOG_IF_IMPL( \ _INFO, ABSL_VLOG_IS_ON(absl_logging_internal_verbose_level)) \ .WithVerbosity(absl_logging_internal_verbose_level) #else @@ -66,7 +66,7 @@ switch (const int absl_logging_internal_verbose_level = (verbose_level)) \ case 0: \ default: \ - ABSL_LOG_INTERNAL_LOG_IF_IMPL( \ + ABSL_LOG_INTERNAL_DLOG_IF_IMPL( \ _INFO, false && ABSL_VLOG_IS_ON(absl_logging_internal_verbose_level)) \ .WithVerbosity(absl_logging_internal_verbose_level) #endif @@ -82,11 +82,11 @@ #ifndef NDEBUG #define ABSL_LOG_INTERNAL_DLOG_IF_IMPL(severity, condition) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATELESS, condition) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #else #define ABSL_LOG_INTERNAL_DLOG_IF_IMPL(severity, condition) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATELESS, false && (condition)) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #endif // ABSL_LOG_EVERY_N @@ -132,36 +132,36 @@ #ifndef NDEBUG #define ABSL_LOG_INTERNAL_DLOG_EVERY_N_IMPL(severity, n) \ ABSL_LOG_INTERNAL_CONDITION_INFO(STATEFUL, true) \ - (EveryN, n) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + (EveryN, n) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_FIRST_N_IMPL(severity, n) \ ABSL_LOG_INTERNAL_CONDITION_INFO(STATEFUL, true) \ - (FirstN, n) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + (FirstN, n) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_EVERY_POW_2_IMPL(severity) \ ABSL_LOG_INTERNAL_CONDITION_INFO(STATEFUL, true) \ - (EveryPow2) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + (EveryPow2) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_EVERY_N_SEC_IMPL(severity, n_seconds) \ ABSL_LOG_INTERNAL_CONDITION_INFO(STATEFUL, true) \ - (EveryNSec, n_seconds) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + (EveryNSec, n_seconds) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #else // def NDEBUG #define ABSL_LOG_INTERNAL_DLOG_EVERY_N_IMPL(severity, n) \ ABSL_LOG_INTERNAL_CONDITION_INFO(STATEFUL, false) \ - (EveryN, n) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + (EveryN, n) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_FIRST_N_IMPL(severity, n) \ ABSL_LOG_INTERNAL_CONDITION_INFO(STATEFUL, false) \ - (FirstN, n) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + (FirstN, n) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_EVERY_POW_2_IMPL(severity) \ ABSL_LOG_INTERNAL_CONDITION_INFO(STATEFUL, false) \ - (EveryPow2) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + (EveryPow2) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_EVERY_N_SEC_IMPL(severity, n_seconds) \ ABSL_LOG_INTERNAL_CONDITION_INFO(STATEFUL, false) \ - (EveryNSec, n_seconds) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + (EveryNSec, n_seconds) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #endif // def NDEBUG #define ABSL_LOG_INTERNAL_VLOG_EVERY_N_IMPL(verbose_level, n) \ @@ -243,40 +243,40 @@ #ifndef NDEBUG #define ABSL_LOG_INTERNAL_DLOG_IF_EVERY_N_IMPL(severity, condition, n) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATEFUL, condition)(EveryN, n) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_IF_FIRST_N_IMPL(severity, condition, n) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATEFUL, condition)(FirstN, n) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_IF_EVERY_POW_2_IMPL(severity, condition) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATEFUL, condition)(EveryPow2) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_IF_EVERY_N_SEC_IMPL(severity, condition, \ n_seconds) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATEFUL, condition)(EveryNSec, \ n_seconds) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #else // def NDEBUG #define ABSL_LOG_INTERNAL_DLOG_IF_EVERY_N_IMPL(severity, condition, n) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATEFUL, false && (condition))( \ - EveryN, n) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + EveryN, n) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_IF_FIRST_N_IMPL(severity, condition, n) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATEFUL, false && (condition))( \ - FirstN, n) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + FirstN, n) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_IF_EVERY_POW_2_IMPL(severity, condition) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATEFUL, false && (condition))( \ - EveryPow2) ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + EveryPow2) ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #define ABSL_LOG_INTERNAL_DLOG_IF_EVERY_N_SEC_IMPL(severity, condition, \ n_seconds) \ ABSL_LOG_INTERNAL_CONDITION##severity(STATEFUL, false && (condition))( \ EveryNSec, n_seconds) \ - ABSL_LOGGING_INTERNAL_LOG##severity.InternalStream() + ABSL_LOGGING_INTERNAL_DLOG##severity.InternalStream() #endif // def NDEBUG #endif // ABSL_LOG_INTERNAL_LOG_IMPL_H_ diff --git a/absl/log/internal/log_message.cc b/absl/log/internal/log_message.cc index 10ac2453..4e9b08af 100644 --- a/absl/log/internal/log_message.cc +++ b/absl/log/internal/log_message.cc @@ -27,6 +27,7 @@ #include <algorithm> #include <array> #include <atomic> +#include <ios> #include <memory> #include <ostream> #include <string> @@ -67,7 +68,14 @@ namespace log_internal { namespace { // message `logging.proto.Event` enum EventTag : uint8_t { + kFileName = 2, + kFileLine = 3, + kTimeNsecs = 4, + kSeverity = 5, + kThreadId = 6, kValue = 7, + kSequenceNumber = 9, + kThreadName = 10, }; // message `logging.proto.Value` @@ -100,6 +108,23 @@ bool PrintValue(absl::Span<char>& dst, absl::Span<const char> buf) { return true; } +// See `logging.proto.Severity` +int32_t ProtoSeverity(absl::LogSeverity severity, int verbose_level) { + switch (severity) { + case absl::LogSeverity::kInfo: + if (verbose_level == absl::LogEntry::kNoVerbosityLevel) return 800; + return 600 - verbose_level; + case absl::LogSeverity::kWarning: + return 900; + case absl::LogSeverity::kError: + return 950; + case absl::LogSeverity::kFatal: + return 1100; + default: + return 800; + } +} + absl::string_view Basename(absl::string_view filepath) { #ifdef _WIN32 size_t path = filepath.find_last_of("/\\"); @@ -145,26 +170,37 @@ struct LogMessage::LogMessageData final { // A `logging.proto.Event` proto message is built into `encoded_buf`. std::array<char, kLogMessageBufferSize> encoded_buf; - // `encoded_remaining` is the suffix of `encoded_buf` that has not been filled - // yet. If a datum to be encoded does not fit into `encoded_remaining` and - // cannot be truncated to fit, the size of `encoded_remaining` will be zeroed - // to prevent encoding of any further data. Note that in this case its data() - // pointer will not point past the end of `encoded_buf`. - absl::Span<char> encoded_remaining; + // `encoded_remaining()` is the suffix of `encoded_buf` that has not been + // filled yet. If a datum to be encoded does not fit into + // `encoded_remaining()` and cannot be truncated to fit, the size of + // `encoded_remaining()` will be zeroed to prevent encoding of any further + // data. Note that in this case its `data()` pointer will not point past the + // end of `encoded_buf`. + // The first use of `encoded_remaining()` is our chance to record metadata + // after any modifications (e.g. by `AtLocation()`) but before any data have + // been recorded. We want to record metadata before data so that data are + // preferentially truncated if we run out of buffer. + absl::Span<char>& encoded_remaining() { + if (encoded_remaining_actual_do_not_use_directly.data() == nullptr) { + encoded_remaining_actual_do_not_use_directly = + absl::MakeSpan(encoded_buf); + InitializeEncodingAndFormat(); + } + return encoded_remaining_actual_do_not_use_directly; + } + absl::Span<char> encoded_remaining_actual_do_not_use_directly; // A formatted string message is built in `string_buf`. std::array<char, kLogMessageBufferSize> string_buf; + void InitializeEncodingAndFormat(); void FinalizeEncodingAndFormat(); }; LogMessage::LogMessageData::LogMessageData(const char* file, int line, absl::LogSeverity severity, absl::Time timestamp) - : extra_sinks_only(false), - manipulated(nullptr), - // This `absl::MakeSpan` silences spurious -Wuninitialized from GCC: - encoded_remaining(absl::MakeSpan(encoded_buf)) { + : extra_sinks_only(false), manipulated(nullptr) { // Legacy defaults for LOG's ostream: manipulated.setf(std::ios_base::showbase | std::ios_base::boolalpha); entry.full_filename_ = file; @@ -177,13 +213,25 @@ LogMessage::LogMessageData::LogMessageData(const char* file, int line, entry.tid_ = absl::base_internal::GetCachedTID(); } +void LogMessage::LogMessageData::InitializeEncodingAndFormat() { + EncodeStringTruncate(EventTag::kFileName, entry.source_filename(), + &encoded_remaining()); + EncodeVarint(EventTag::kFileLine, entry.source_line(), &encoded_remaining()); + EncodeVarint(EventTag::kTimeNsecs, absl::ToUnixNanos(entry.timestamp()), + &encoded_remaining()); + EncodeVarint(EventTag::kSeverity, + ProtoSeverity(entry.log_severity(), entry.verbosity()), + &encoded_remaining()); + EncodeVarint(EventTag::kThreadId, entry.tid(), &encoded_remaining()); +} + void LogMessage::LogMessageData::FinalizeEncodingAndFormat() { - // Note that `encoded_remaining` may have zero size without pointing past the - // end of `encoded_buf`, so the difference between `data()` pointers is used - // to compute the size of `encoded_data`. + // Note that `encoded_remaining()` may have zero size without pointing past + // the end of `encoded_buf`, so the difference between `data()` pointers is + // used to compute the size of `encoded_data`. absl::Span<const char> encoded_data( encoded_buf.data(), - static_cast<size_t>(encoded_remaining.data() - encoded_buf.data())); + static_cast<size_t>(encoded_remaining().data() - encoded_buf.data())); // `string_remaining` is the suffix of `string_buf` that has not been filled // yet. absl::Span<char> string_remaining(string_buf); @@ -211,7 +259,6 @@ void LogMessage::LogMessageData::FinalizeEncodingAndFormat() { if (PrintValue(string_remaining, field.bytes_value())) continue; break; } - break; } auto chars_written = static_cast<size_t>(string_remaining.data() - string_buf.data()); @@ -413,7 +460,7 @@ void LogMessage::Flush() { data_->FinalizeEncodingAndFormat(); data_->entry.encoding_ = absl::string_view(data_->encoded_buf.data(), - static_cast<size_t>(data_->encoded_remaining.data() - + static_cast<size_t>(data_->encoded_remaining().data() - data_->encoded_buf.data())); SendToLog(); } @@ -421,7 +468,7 @@ void LogMessage::Flush() { void LogMessage::SetFailQuietly() { data_->fail_quietly = true; } LogMessage::OstreamView::OstreamView(LogMessageData& message_data) - : data_(message_data), encoded_remaining_copy_(data_.encoded_remaining) { + : data_(message_data), encoded_remaining_copy_(data_.encoded_remaining()) { // This constructor sets the `streambuf` up so that streaming into an attached // ostream encodes string data in-place. To do that, we write appropriate // headers into the buffer using a copy of the buffer view so that we can @@ -444,8 +491,8 @@ LogMessage::OstreamView::~OstreamView() { if (!string_start_.data()) { // The second field header didn't fit. Whether the first one did or not, we // shouldn't commit `encoded_remaining_copy_`, and we also need to zero the - // size of `data_->encoded_remaining` so that no more data are encoded. - data_.encoded_remaining.remove_suffix(data_.encoded_remaining.size()); + // size of `data_->encoded_remaining()` so that no more data are encoded. + data_.encoded_remaining().remove_suffix(data_.encoded_remaining().size()); return; } const absl::Span<const char> contents(pbase(), @@ -454,7 +501,7 @@ LogMessage::OstreamView::~OstreamView() { encoded_remaining_copy_.remove_prefix(contents.size()); EncodeMessageLength(string_start_, &encoded_remaining_copy_); EncodeMessageLength(message_start_, &encoded_remaining_copy_); - data_.encoded_remaining = encoded_remaining_copy_; + data_.encoded_remaining() = encoded_remaining_copy_; } std::ostream& LogMessage::OstreamView::stream() { return data_.manipulated; } @@ -521,13 +568,13 @@ void LogMessage::LogBacktraceIfNeeded() { view.stream() << ") "; } -// Encodes into `data_->encoded_remaining` a partial `logging.proto.Event` +// Encodes into `data_->encoded_remaining()` a partial `logging.proto.Event` // containing the specified string data using a `Value` field appropriate to // `str_type`. Truncates `str` if necessary, but emits nothing and marks the // buffer full if even the field headers do not fit. template <LogMessage::StringType str_type> void LogMessage::CopyToEncodedBuffer(absl::string_view str) { - auto encoded_remaining_copy = data_->encoded_remaining; + auto encoded_remaining_copy = data_->encoded_remaining(); auto start = EncodeMessageStart( EventTag::kValue, BufferSizeFor(WireType::kLengthDelimited) + str.size(), &encoded_remaining_copy); @@ -540,11 +587,11 @@ void LogMessage::CopyToEncodedBuffer(absl::string_view str) { str, &encoded_remaining_copy)) { // The string may have been truncated, but the field header fit. EncodeMessageLength(start, &encoded_remaining_copy); - data_->encoded_remaining = encoded_remaining_copy; + data_->encoded_remaining() = encoded_remaining_copy; } else { - // The field header(s) did not fit; zero `encoded_remaining` so we don't + // The field header(s) did not fit; zero `encoded_remaining()` so we don't // write anything else later. - data_->encoded_remaining.remove_suffix(data_->encoded_remaining.size()); + data_->encoded_remaining().remove_suffix(data_->encoded_remaining().size()); } } template void LogMessage::CopyToEncodedBuffer<LogMessage::StringType::kLiteral>( @@ -553,7 +600,7 @@ template void LogMessage::CopyToEncodedBuffer< LogMessage::StringType::kNotLiteral>(absl::string_view str); template <LogMessage::StringType str_type> void LogMessage::CopyToEncodedBuffer(char ch, size_t num) { - auto encoded_remaining_copy = data_->encoded_remaining; + auto encoded_remaining_copy = data_->encoded_remaining(); auto value_start = EncodeMessageStart( EventTag::kValue, BufferSizeFor(WireType::kLengthDelimited) + num, &encoded_remaining_copy); @@ -566,11 +613,11 @@ void LogMessage::CopyToEncodedBuffer(char ch, size_t num) { log_internal::AppendTruncated(ch, num, encoded_remaining_copy); EncodeMessageLength(str_start, &encoded_remaining_copy); EncodeMessageLength(value_start, &encoded_remaining_copy); - data_->encoded_remaining = encoded_remaining_copy; + data_->encoded_remaining() = encoded_remaining_copy; } else { - // The field header(s) did not fit; zero `encoded_remaining` so we don't + // The field header(s) did not fit; zero `encoded_remaining()` so we don't // write anything else later. - data_->encoded_remaining.remove_suffix(data_->encoded_remaining.size()); + data_->encoded_remaining().remove_suffix(data_->encoded_remaining().size()); } } template void LogMessage::CopyToEncodedBuffer<LogMessage::StringType::kLiteral>( @@ -578,6 +625,13 @@ template void LogMessage::CopyToEncodedBuffer<LogMessage::StringType::kLiteral>( template void LogMessage::CopyToEncodedBuffer< LogMessage::StringType::kNotLiteral>(char ch, size_t num); +// We intentionally don't return from these destructors. Disable MSVC's warning +// about the destructor never returning as we do so intentionally here. +#if defined(_MSC_VER) && !defined(__clang__) +#pragma warning(push) +#pragma warning(disable : 4722) +#endif + LogMessageFatal::LogMessageFatal(const char* file, int line) : LogMessage(file, line, absl::LogSeverity::kFatal) {} @@ -587,19 +641,29 @@ LogMessageFatal::LogMessageFatal(const char* file, int line, *this << "Check failed: " << failure_msg << " "; } -// ABSL_ATTRIBUTE_NORETURN doesn't seem to work on destructors with msvc, so -// disable msvc's warning about the d'tor never returning. -#if defined(_MSC_VER) && !defined(__clang__) -#pragma warning(push) -#pragma warning(disable : 4722) -#endif LogMessageFatal::~LogMessageFatal() { Flush(); FailWithoutStackTrace(); } -#if defined(_MSC_VER) && !defined(__clang__) -#pragma warning(pop) -#endif + +LogMessageDebugFatal::LogMessageDebugFatal(const char* file, int line) + : LogMessage(file, line, absl::LogSeverity::kFatal) {} + +LogMessageDebugFatal::~LogMessageDebugFatal() { + Flush(); + FailWithoutStackTrace(); +} + +LogMessageQuietlyDebugFatal::LogMessageQuietlyDebugFatal(const char* file, + int line) + : LogMessage(file, line, absl::LogSeverity::kFatal) { + SetFailQuietly(); +} + +LogMessageQuietlyDebugFatal::~LogMessageQuietlyDebugFatal() { + Flush(); + FailQuietly(); +} LogMessageQuietlyFatal::LogMessageQuietlyFatal(const char* file, int line) : LogMessage(file, line, absl::LogSeverity::kFatal) { @@ -608,17 +672,10 @@ LogMessageQuietlyFatal::LogMessageQuietlyFatal(const char* file, int line) LogMessageQuietlyFatal::LogMessageQuietlyFatal(const char* file, int line, absl::string_view failure_msg) - : LogMessage(file, line, absl::LogSeverity::kFatal) { - SetFailQuietly(); - *this << "Check failed: " << failure_msg << " "; + : LogMessageQuietlyFatal(file, line) { + *this << "Check failed: " << failure_msg << " "; } -// ABSL_ATTRIBUTE_NORETURN doesn't seem to work on destructors with msvc, so -// disable msvc's warning about the d'tor never returning. -#if defined(_MSC_VER) && !defined(__clang__) -#pragma warning(push) -#pragma warning(disable : 4722) -#endif LogMessageQuietlyFatal::~LogMessageQuietlyFatal() { Flush(); FailQuietly(); diff --git a/absl/log/internal/log_message.h b/absl/log/internal/log_message.h index 4ecb8a14..0c067da9 100644 --- a/absl/log/internal/log_message.h +++ b/absl/log/internal/log_message.h @@ -187,11 +187,11 @@ class LogMessage { protected: // Call `abort()` or similar to perform `LOG(FATAL)` crash. It is assumed // that the caller has already generated and written the trace as appropriate. - ABSL_ATTRIBUTE_NORETURN static void FailWithoutStackTrace(); + [[noreturn]] static void FailWithoutStackTrace(); // Similar to `FailWithoutStackTrace()`, but without `abort()`. Terminates // the process with an error exit code. - ABSL_ATTRIBUTE_NORETURN static void FailQuietly(); + [[noreturn]] static void FailQuietly(); // Dispatches the completed `absl::LogEntry` to applicable `absl::LogSink`s. // This might as well be inlined into `~LogMessage` except that @@ -354,15 +354,34 @@ class LogMessageFatal final : public LogMessage { LogMessageFatal(const char* file, int line) ABSL_ATTRIBUTE_COLD; LogMessageFatal(const char* file, int line, absl::string_view failure_msg) ABSL_ATTRIBUTE_COLD; - ABSL_ATTRIBUTE_NORETURN ~LogMessageFatal(); + [[noreturn]] ~LogMessageFatal(); }; +// `LogMessageDebugFatal` ensures the process will exit in failure after logging +// this message. It matches LogMessageFatal but is not [[noreturn]] as it's used +// for DLOG(FATAL) variants. +class LogMessageDebugFatal final : public LogMessage { + public: + LogMessageDebugFatal(const char* file, int line) ABSL_ATTRIBUTE_COLD; + ~LogMessageDebugFatal(); +}; + +class LogMessageQuietlyDebugFatal final : public LogMessage { + public: + // DLOG(QFATAL) calls this instead of LogMessageQuietlyFatal to make sure the + // destructor is not [[noreturn]] even if this is always FATAL as this is only + // invoked when DLOG() is enabled. + LogMessageQuietlyDebugFatal(const char* file, int line) ABSL_ATTRIBUTE_COLD; + ~LogMessageQuietlyDebugFatal(); +}; + +// Used for LOG(QFATAL) to make sure it's properly understood as [[noreturn]]. class LogMessageQuietlyFatal final : public LogMessage { public: LogMessageQuietlyFatal(const char* file, int line) ABSL_ATTRIBUTE_COLD; LogMessageQuietlyFatal(const char* file, int line, absl::string_view failure_msg) ABSL_ATTRIBUTE_COLD; - ABSL_ATTRIBUTE_NORETURN ~LogMessageQuietlyFatal(); + [[noreturn]] ~LogMessageQuietlyFatal(); }; } // namespace log_internal diff --git a/absl/log/internal/nullstream.h b/absl/log/internal/nullstream.h index 9266852e..973e91ab 100644 --- a/absl/log/internal/nullstream.h +++ b/absl/log/internal/nullstream.h @@ -117,16 +117,7 @@ class NullStreamMaybeFatal final : public NullStream { class NullStreamFatal final : public NullStream { public: NullStreamFatal() = default; - // ABSL_ATTRIBUTE_NORETURN doesn't seem to work on destructors with msvc, so - // disable msvc's warning about the d'tor never returning. -#if defined(_MSC_VER) && !defined(__clang__) -#pragma warning(push) -#pragma warning(disable : 4722) -#endif - ABSL_ATTRIBUTE_NORETURN ~NullStreamFatal() { _exit(1); } -#if defined(_MSC_VER) && !defined(__clang__) -#pragma warning(pop) -#endif + [[noreturn]] ~NullStreamFatal() { _exit(1); } }; } // namespace log_internal diff --git a/absl/log/internal/strip.h b/absl/log/internal/strip.h index f8d27869..3e550104 100644 --- a/absl/log/internal/strip.h +++ b/absl/log/internal/strip.h @@ -20,6 +20,7 @@ #ifndef ABSL_LOG_INTERNAL_STRIP_H_ #define ABSL_LOG_INTERNAL_STRIP_H_ +#include "absl/base/attributes.h" // IWYU pragma: keep #include "absl/base/log_severity.h" #include "absl/log/internal/log_message.h" #include "absl/log/internal/nullstream.h" @@ -29,6 +30,16 @@ // of defines comes in three flavors: vanilla, plus two variants that strip some // logging in subtly different ways for subtly different reasons (see below). #if defined(STRIP_LOG) && STRIP_LOG + +// Attribute for marking variables used in implementation details of logging +// macros as unused, but only when `STRIP_LOG` is defined. +// With `STRIP_LOG` on, not marking them triggers `-Wunused-but-set-variable`, +// With `STRIP_LOG` off, marking them triggers `-Wused-but-marked-unused`. +// +// TODO(b/290784225): Replace this macro with attribute [[maybe_unused]] when +// Abseil stops supporting C++14. +#define ABSL_LOG_INTERNAL_ATTRIBUTE_UNUSED_IF_STRIP_LOG ABSL_ATTRIBUTE_UNUSED + #define ABSL_LOGGING_INTERNAL_LOG_INFO ::absl::log_internal::NullStream() #define ABSL_LOGGING_INTERNAL_LOG_WARNING ::absl::log_internal::NullStream() #define ABSL_LOGGING_INTERNAL_LOG_ERROR ::absl::log_internal::NullStream() @@ -38,10 +49,21 @@ ::absl::log_internal::NullStreamMaybeFatal(::absl::kLogDebugFatal) #define ABSL_LOGGING_INTERNAL_LOG_LEVEL(severity) \ ::absl::log_internal::NullStreamMaybeFatal(absl_log_internal_severity) + +// Fatal `DLOG`s expand a little differently to avoid being `[[noreturn]]`. +#define ABSL_LOGGING_INTERNAL_DLOG_FATAL \ + ::absl::log_internal::NullStreamMaybeFatal(::absl::LogSeverity::kFatal) +#define ABSL_LOGGING_INTERNAL_DLOG_QFATAL \ + ::absl::log_internal::NullStreamMaybeFatal(::absl::LogSeverity::kFatal) + #define ABSL_LOG_INTERNAL_CHECK(failure_message) ABSL_LOGGING_INTERNAL_LOG_FATAL #define ABSL_LOG_INTERNAL_QCHECK(failure_message) \ ABSL_LOGGING_INTERNAL_LOG_QFATAL + #else // !defined(STRIP_LOG) || !STRIP_LOG + +#define ABSL_LOG_INTERNAL_ATTRIBUTE_UNUSED_IF_STRIP_LOG + #define ABSL_LOGGING_INTERNAL_LOG_INFO \ ::absl::log_internal::LogMessage( \ __FILE__, __LINE__, ::absl::log_internal::LogMessage::InfoTag{}) @@ -60,6 +82,13 @@ #define ABSL_LOGGING_INTERNAL_LOG_LEVEL(severity) \ ::absl::log_internal::LogMessage(__FILE__, __LINE__, \ absl_log_internal_severity) + +// Fatal `DLOG`s expand a little differently to avoid being `[[noreturn]]`. +#define ABSL_LOGGING_INTERNAL_DLOG_FATAL \ + ::absl::log_internal::LogMessageDebugFatal(__FILE__, __LINE__) +#define ABSL_LOGGING_INTERNAL_DLOG_QFATAL \ + ::absl::log_internal::LogMessageQuietlyDebugFatal(__FILE__, __LINE__) + // These special cases dispatch to special-case constructors that allow us to // avoid an extra function call and shrink non-LTO binaries by a percent or so. #define ABSL_LOG_INTERNAL_CHECK(failure_message) \ @@ -69,4 +98,11 @@ failure_message) #endif // !defined(STRIP_LOG) || !STRIP_LOG +// This part of a non-fatal `DLOG`s expands the same as `LOG`. +#define ABSL_LOGGING_INTERNAL_DLOG_INFO ABSL_LOGGING_INTERNAL_LOG_INFO +#define ABSL_LOGGING_INTERNAL_DLOG_WARNING ABSL_LOGGING_INTERNAL_LOG_WARNING +#define ABSL_LOGGING_INTERNAL_DLOG_ERROR ABSL_LOGGING_INTERNAL_LOG_ERROR +#define ABSL_LOGGING_INTERNAL_DLOG_DFATAL ABSL_LOGGING_INTERNAL_LOG_DFATAL +#define ABSL_LOGGING_INTERNAL_DLOG_LEVEL ABSL_LOGGING_INTERNAL_LOG_LEVEL + #endif // ABSL_LOG_INTERNAL_STRIP_H_ diff --git a/absl/log/internal/test_matchers.cc b/absl/log/internal/test_matchers.cc index 8c6515c4..042083d8 100644 --- a/absl/log/internal/test_matchers.cc +++ b/absl/log/internal/test_matchers.cc @@ -26,6 +26,7 @@ #include "absl/base/attributes.h" #include "absl/base/config.h" #include "absl/log/internal/test_helpers.h" +#include "absl/log/log_entry.h" #include "absl/strings/string_view.h" #include "absl/time/clock.h" #include "absl/time/time.h" @@ -131,11 +132,9 @@ Matcher<const absl::LogEntry&> Timestamp( return Property("timestamp", &absl::LogEntry::timestamp, timestamp); } -Matcher<const absl::LogEntry&> TimestampInMatchWindow() { - return Property("timestamp", &absl::LogEntry::timestamp, - AllOf(Ge(absl::Now()), Truly([](absl::Time arg) { - return arg <= absl::Now(); - }))); +Matcher<absl::Time> InMatchWindow() { + return AllOf(Ge(absl::Now()), + Truly([](absl::Time arg) { return arg <= absl::Now(); })); } Matcher<const absl::LogEntry&> ThreadID( diff --git a/absl/log/internal/test_matchers.h b/absl/log/internal/test_matchers.h index fc653a91..906eda24 100644 --- a/absl/log/internal/test_matchers.h +++ b/absl/log/internal/test_matchers.h @@ -62,7 +62,7 @@ namespace log_internal { const ::testing::Matcher<absl::Time>& timestamp); // Matches if the `LogEntry`'s timestamp falls after the instantiation of this // matcher and before its execution, as is normal when used with EXPECT_CALL. -::testing::Matcher<const absl::LogEntry&> TimestampInMatchWindow(); +::testing::Matcher<absl::Time> InMatchWindow(); ::testing::Matcher<const absl::LogEntry&> ThreadID( const ::testing::Matcher<absl::LogEntry::tid_t>&); ::testing::Matcher<const absl::LogEntry&> TextMessageWithPrefixAndNewline( diff --git a/absl/log/log.h b/absl/log/log.h index b721b087..a4e1d1fe 100644 --- a/absl/log/log.h +++ b/absl/log/log.h @@ -198,7 +198,6 @@ #define ABSL_LOG_LOG_H_ #include "absl/log/internal/log_impl.h" -#include "absl/log/vlog_is_on.h" // IWYU pragma: export // LOG() // @@ -234,6 +233,11 @@ // // See vlog_is_on.h for further documentation, including the usage of the // --vmodule flag to log at different levels in different source files. +// +// `VLOG` does not produce any output when verbose logging is not enabled. +// However, simply testing whether verbose logging is enabled can be expensive. +// If you don't intend to enable verbose logging in non-debug builds, consider +// using `DVLOG` instead. #define VLOG(severity) ABSL_LOG_INTERNAL_VLOG_IMPL(severity) // `DVLOG` behaves like `VLOG` in debug mode (i.e. `#ifndef NDEBUG`). diff --git a/absl/log/log_basic_test.cc b/absl/log/log_basic_test.cc index 7fc7111d..ef8967af 100644 --- a/absl/log/log_basic_test.cc +++ b/absl/log/log_basic_test.cc @@ -16,6 +16,7 @@ #include "absl/log/log.h" #define ABSL_TEST_LOG LOG +#define ABSL_TEST_DLOG DLOG #include "gtest/gtest.h" #include "absl/log/log_basic_test_impl.inc" diff --git a/absl/log/log_basic_test_impl.inc b/absl/log/log_basic_test_impl.inc index e2f33566..7baf5e7b 100644 --- a/absl/log/log_basic_test_impl.inc +++ b/absl/log/log_basic_test_impl.inc @@ -25,6 +25,10 @@ #error ABSL_TEST_LOG must be defined for these tests to work. #endif +#ifndef ABSL_TEST_DLOG +#error ABSL_TEST_DLOG must be defined for these tests to work. +#endif + #include <cerrno> #include <sstream> #include <string> @@ -34,6 +38,7 @@ #include "absl/base/internal/sysinfo.h" #include "absl/base/log_severity.h" #include "absl/log/globals.h" +#include "absl/log/internal/globals.h" #include "absl/log/internal/test_actions.h" #include "absl/log/internal/test_helpers.h" #include "absl/log/internal/test_matchers.h" @@ -48,6 +53,7 @@ using ::absl::log_internal::DeathTestValidateExpectations; using ::absl::log_internal::DiedOfFatal; using ::absl::log_internal::DiedOfQFatal; #endif +using ::absl::log_internal::InMatchWindow; using ::absl::log_internal::LoggingEnabledAt; using ::absl::log_internal::LogSeverity; using ::absl::log_internal::Prefix; @@ -57,7 +63,7 @@ using ::absl::log_internal::SourceLine; using ::absl::log_internal::Stacktrace; using ::absl::log_internal::TextMessage; using ::absl::log_internal::ThreadID; -using ::absl::log_internal::TimestampInMatchWindow; +using ::absl::log_internal::Timestamp; using ::absl::log_internal::Verbosity; using ::testing::AnyNumber; using ::testing::Eq; @@ -93,18 +99,20 @@ TEST_P(BasicLogTest, Info) { if (LoggingEnabledAt(absl::LogSeverity::kInfo)) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq(__FILE__)), - SourceBasename(Eq("log_basic_test_impl.inc")), - SourceLine(Eq(log_line)), Prefix(IsTrue()), - LogSeverity(Eq(absl::LogSeverity::kInfo)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("hello world")), - Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - literal: "hello world" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq(__FILE__)), + SourceBasename(Eq("log_basic_test_impl.inc")), + SourceLine(Eq(log_line)), Prefix(IsTrue()), + LogSeverity(Eq(absl::LogSeverity::kInfo)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("hello world")), + Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::INFO), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(literal: "hello world")pb")))), + Stacktrace(IsEmpty())))); } test_sink.StartCapturingLogs(); @@ -122,18 +130,20 @@ TEST_P(BasicLogTest, Warning) { if (LoggingEnabledAt(absl::LogSeverity::kWarning)) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq(__FILE__)), - SourceBasename(Eq("log_basic_test_impl.inc")), - SourceLine(Eq(log_line)), Prefix(IsTrue()), - LogSeverity(Eq(absl::LogSeverity::kWarning)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("hello world")), - Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - literal: "hello world" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq(__FILE__)), + SourceBasename(Eq("log_basic_test_impl.inc")), + SourceLine(Eq(log_line)), Prefix(IsTrue()), + LogSeverity(Eq(absl::LogSeverity::kWarning)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("hello world")), + Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::WARNING), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(literal: "hello world")pb")))), + Stacktrace(IsEmpty())))); } test_sink.StartCapturingLogs(); @@ -151,18 +161,20 @@ TEST_P(BasicLogTest, Error) { if (LoggingEnabledAt(absl::LogSeverity::kError)) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq(__FILE__)), - SourceBasename(Eq("log_basic_test_impl.inc")), - SourceLine(Eq(log_line)), Prefix(IsTrue()), - LogSeverity(Eq(absl::LogSeverity::kError)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("hello world")), - Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - literal: "hello world" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq(__FILE__)), + SourceBasename(Eq("log_basic_test_impl.inc")), + SourceLine(Eq(log_line)), Prefix(IsTrue()), + LogSeverity(Eq(absl::LogSeverity::kError)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("hello world")), + Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::ERROR), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(literal: "hello world")pb")))), + Stacktrace(IsEmpty())))); } test_sink.StartCapturingLogs(); @@ -206,12 +218,16 @@ TEST_P(BasicLogDeathTest, Fatal) { SourceBasename(Eq("log_basic_test_impl.inc")), SourceLine(Eq(log_line)), Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), + Timestamp(InMatchWindow()), ThreadID(Eq(absl::base_internal::GetTID())), TextMessage(Eq("hello world")), Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { literal: "hello world" })pb")), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(literal: "hello world")pb")))), Stacktrace(IsEmpty())))) .WillOnce(DeathTestExpectedLogging()); @@ -222,12 +238,16 @@ TEST_P(BasicLogDeathTest, Fatal) { SourceBasename(Eq("log_basic_test_impl.inc")), SourceLine(Eq(log_line)), Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), + Timestamp(InMatchWindow()), ThreadID(Eq(absl::base_internal::GetTID())), TextMessage(Eq("hello world")), Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { literal: "hello world" })pb")), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(literal: "hello world")pb")))), Stacktrace(Not(IsEmpty()))))) .WillOnce(DeathTestExpectedLogging()); } @@ -260,12 +280,16 @@ TEST_P(BasicLogDeathTest, QFatal) { SourceBasename(Eq("log_basic_test_impl.inc")), SourceLine(Eq(log_line)), Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), + Timestamp(InMatchWindow()), ThreadID(Eq(absl::base_internal::GetTID())), TextMessage(Eq("hello world")), Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { literal: "hello world" })pb")), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(literal: "hello world")pb")))), Stacktrace(IsEmpty())))) .WillOnce(DeathTestExpectedLogging()); } @@ -289,18 +313,20 @@ TEST_P(BasicLogTest, DFatal) { if (LoggingEnabledAt(absl::LogSeverity::kError)) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq(__FILE__)), - SourceBasename(Eq("log_basic_test_impl.inc")), - SourceLine(Eq(log_line)), Prefix(IsTrue()), - LogSeverity(Eq(absl::LogSeverity::kError)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("hello world")), - Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - literal: "hello world" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq(__FILE__)), + SourceBasename(Eq("log_basic_test_impl.inc")), + SourceLine(Eq(log_line)), Prefix(IsTrue()), + LogSeverity(Eq(absl::LogSeverity::kError)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("hello world")), + Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::ERROR), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(literal: "hello world")pb")))), + Stacktrace(IsEmpty())))); } test_sink.StartCapturingLogs(); @@ -334,12 +360,16 @@ TEST_P(BasicLogDeathTest, DFatal) { SourceBasename(Eq("log_basic_test_impl.inc")), SourceLine(Eq(log_line)), Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), + Timestamp(InMatchWindow()), ThreadID(Eq(absl::base_internal::GetTID())), TextMessage(Eq("hello world")), Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { literal: "hello world" })pb")), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(literal: "hello world")pb")))), Stacktrace(IsEmpty())))) .WillOnce(DeathTestExpectedLogging()); @@ -350,12 +380,16 @@ TEST_P(BasicLogDeathTest, DFatal) { SourceBasename(Eq("log_basic_test_impl.inc")), SourceLine(Eq(log_line)), Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), + Timestamp(InMatchWindow()), ThreadID(Eq(absl::base_internal::GetTID())), TextMessage(Eq("hello world")), Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { literal: "hello world" })pb")), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(literal: "hello world")pb")))), Stacktrace(Not(IsEmpty()))))) .WillOnce(DeathTestExpectedLogging()); } @@ -367,6 +401,27 @@ TEST_P(BasicLogDeathTest, DFatal) { } #endif +#ifndef NDEBUG +TEST_P(BasicLogTest, DFatalIsCancellable) { + // LOG(DFATAL) does not die when DFATAL death is disabled. + absl::log_internal::SetExitOnDFatal(false); + ABSL_TEST_LOG(DFATAL) << "hello world"; + absl::log_internal::SetExitOnDFatal(true); +} + +#if GTEST_HAS_DEATH_TEST +TEST_P(BasicLogDeathTest, DLogFatalIsNotCancellable) { + EXPECT_EXIT( + { + absl::log_internal::SetExitOnDFatal(false); + ABSL_TEST_DLOG(FATAL) << "hello world"; + absl::log_internal::SetExitOnDFatal(true); + }, + DiedOfFatal, ""); +} +#endif +#endif + TEST_P(BasicLogTest, Level) { absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); @@ -382,17 +437,25 @@ TEST_P(BasicLogTest, Level) { if (LoggingEnabledAt(severity)) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq(__FILE__)), - SourceBasename(Eq("log_basic_test_impl.inc")), - SourceLine(Eq(log_line)), Prefix(IsTrue()), - LogSeverity(Eq(severity)), TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("hello world")), - Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - literal: "hello world" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq(__FILE__)), + SourceBasename(Eq("log_basic_test_impl.inc")), + SourceLine(Eq(log_line)), Prefix(IsTrue()), + LogSeverity(Eq(severity)), Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("hello world")), + Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(severity == absl::LogSeverity::kInfo ? logging::proto::INFO + : severity == absl::LogSeverity::kWarning + ? logging::proto::WARNING + : severity == absl::LogSeverity::kError + ? logging::proto::ERROR + : 0), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(literal: "hello world")pb")))), + Stacktrace(IsEmpty())))); } test_sink.StartCapturingLogs(); do_log(); @@ -429,12 +492,16 @@ TEST_P(BasicLogDeathTest, Level) { SourceBasename(Eq("log_basic_test_impl.inc")), SourceLine(Eq(log_line)), Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), + Timestamp(InMatchWindow()), ThreadID(Eq(absl::base_internal::GetTID())), TextMessage(Eq("hello world")), Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { literal: "hello world" })pb")), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(literal: "hello world")pb")))), Stacktrace(IsEmpty())))) .WillOnce(DeathTestExpectedLogging()); @@ -444,12 +511,16 @@ TEST_P(BasicLogDeathTest, Level) { SourceBasename(Eq("log_basic_test_impl.inc")), SourceLine(Eq(log_line)), Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), + Timestamp(InMatchWindow()), ThreadID(Eq(absl::base_internal::GetTID())), TextMessage(Eq("hello world")), Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { literal: "hello world" })pb")), + ENCODED_MESSAGE(MatchesEvent( + Eq(__FILE__), Eq(log_line), InMatchWindow(), + Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(literal: "hello world")pb")))), Stacktrace(Not(IsEmpty()))))) .WillOnce(DeathTestExpectedLogging()); } diff --git a/absl/log/log_benchmark.cc b/absl/log/log_benchmark.cc index 45d9a5d6..60c0fd63 100644 --- a/absl/log/log_benchmark.cc +++ b/absl/log/log_benchmark.cc @@ -17,10 +17,12 @@ #include "absl/flags/flag.h" #include "absl/log/check.h" #include "absl/log/globals.h" +#include "absl/log/internal/flags.h" #include "absl/log/log.h" #include "absl/log/log_entry.h" #include "absl/log/log_sink.h" #include "absl/log/log_sink_registry.h" +#include "absl/log/vlog_is_on.h" #include "benchmark/benchmark.h" namespace { @@ -93,5 +95,70 @@ static void BM_EnabledLogOverhead(benchmark::State& state) { } BENCHMARK(BM_EnabledLogOverhead); +static void BM_VlogIsOnOverhead(benchmark::State& state) { + // It would make sense to do this only when state.thread_index == 0, + // but thread_index is an int on some platforms (e.g. Android) and a + // function returning an int on others. So we just do it on all threads. + // TODO(b/152609127): set only if thread_index == 0. + absl::SetFlag(&FLAGS_v, 0); + + while (state.KeepRunningBatch(10)) { + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 1 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 2 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 3 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 4 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 5 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 6 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 7 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 8 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 9 + benchmark::DoNotOptimize(VLOG_IS_ON(0)); // 10 + } +} +BENCHMARK(BM_VlogIsOnOverhead)->ThreadRange(1, 64); + +static void BM_VlogIsNotOnOverhead(benchmark::State& state) { + // It would make sense to do this only when state.thread_index == 0, + // but thread_index is an int on some platforms (e.g. Android) and a + // function returning an int on others. So we just do it on all threads. + // TODO(b/152609127): set only if thread_index == 0. + absl::SetFlag(&FLAGS_v, 0); + + while (state.KeepRunningBatch(10)) { + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 1 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 2 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 3 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 4 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 5 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 6 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 7 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 8 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 9 + benchmark::DoNotOptimize(VLOG_IS_ON(1)); // 10 + } +} +BENCHMARK(BM_VlogIsNotOnOverhead)->ThreadRange(1, 64); + +static void BM_LogEveryNOverhead(benchmark::State& state) { + absl::ScopedStderrThreshold disable_stderr_logging( + absl::LogSeverityAtLeast::kInfinity); + absl::SetMinLogLevel(absl::LogSeverityAtLeast::kInfinity); + ABSL_ATTRIBUTE_UNUSED NullLogSink null_sink; + + while (state.KeepRunningBatch(10)) { + LOG_EVERY_N_SEC(INFO, 10); + LOG_EVERY_N_SEC(INFO, 20); + LOG_EVERY_N_SEC(INFO, 30); + LOG_EVERY_N_SEC(INFO, 40); + LOG_EVERY_N_SEC(INFO, 50); + LOG_EVERY_N_SEC(INFO, 60); + LOG_EVERY_N_SEC(INFO, 70); + LOG_EVERY_N_SEC(INFO, 80); + LOG_EVERY_N_SEC(INFO, 90); + LOG_EVERY_N_SEC(INFO, 100); + } +} +BENCHMARK(BM_LogEveryNOverhead)->ThreadRange(1, 64); + } // namespace diff --git a/absl/log/log_format_test.cc b/absl/log/log_format_test.cc index dbad5d97..beee966d 100644 --- a/absl/log/log_format_test.cc +++ b/absl/log/log_format_test.cc @@ -78,7 +78,7 @@ TEST(LogFormatTest, NoMessage) { TextPrefix(AsString(EndsWith(absl::StrCat( " log_format_test.cc:", log_line, "] ")))), TextMessage(IsEmpty()), - ENCODED_MESSAGE(EqualsProto(R"pb()pb"))))); + ENCODED_MESSAGE(HasValues(IsEmpty()))))); test_sink.StartCapturingLogs(); do_log(); @@ -96,11 +96,11 @@ TYPED_TEST(CharLogFormatTest, Printable) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("x")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "x" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("x")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "x")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -113,12 +113,11 @@ TYPED_TEST(CharLogFormatTest, Unprintable) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("\xee")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "\xee" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("\xee")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "\xee")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -137,11 +136,11 @@ TYPED_TEST(UnsignedIntLogFormatTest, Positive) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("224")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "224" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("224")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "224")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -156,11 +155,11 @@ TYPED_TEST(UnsignedIntLogFormatTest, BitfieldPositive) { auto comparison_stream = ComparisonStream(); comparison_stream << value.bits; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("42")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "42" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("42")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "42")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value.bits; @@ -179,11 +178,11 @@ TYPED_TEST(SignedIntLogFormatTest, Positive) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("224")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "224" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("224")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "224")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -196,12 +195,11 @@ TYPED_TEST(SignedIntLogFormatTest, Negative) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("-112")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "-112" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("-112")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "-112")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -216,11 +214,11 @@ TYPED_TEST(SignedIntLogFormatTest, BitfieldPositive) { auto comparison_stream = ComparisonStream(); comparison_stream << value.bits; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("21")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "21" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("21")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "21")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value.bits; @@ -235,11 +233,11 @@ TYPED_TEST(SignedIntLogFormatTest, BitfieldNegative) { auto comparison_stream = ComparisonStream(); comparison_stream << value.bits; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("-21")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "-21" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("-21")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "-21")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value.bits; @@ -276,11 +274,11 @@ TYPED_TEST(UnsignedEnumLogFormatTest, Positive) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("224")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "224" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("224")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "224")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -295,11 +293,11 @@ TYPED_TEST(UnsignedEnumLogFormatTest, BitfieldPositive) { auto comparison_stream = ComparisonStream(); comparison_stream << value.bits; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("42")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "42" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("42")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "42")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value.bits; @@ -335,11 +333,11 @@ TYPED_TEST(SignedEnumLogFormatTest, Positive) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("224")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "224" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("224")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "224")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -352,12 +350,11 @@ TYPED_TEST(SignedEnumLogFormatTest, Negative) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("-112")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "-112" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("-112")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "-112")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -372,11 +369,11 @@ TYPED_TEST(SignedEnumLogFormatTest, BitfieldPositive) { auto comparison_stream = ComparisonStream(); comparison_stream << value.bits; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("21")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "21" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("21")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "21")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value.bits; @@ -391,11 +388,11 @@ TYPED_TEST(SignedEnumLogFormatTest, BitfieldNegative) { auto comparison_stream = ComparisonStream(); comparison_stream << value.bits; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("-21")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "-21" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("-21")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "-21")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value.bits; @@ -412,9 +409,8 @@ TEST(FloatLogFormatTest, Positive) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("6.02e+23")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "6.02e+23" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "6.02e+23")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -430,9 +426,8 @@ TEST(FloatLogFormatTest, Negative) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("-6.02e+23")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "-6.02e+23" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "-6.02e+23")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -448,9 +443,8 @@ TEST(FloatLogFormatTest, NegativeExponent) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("6.02e-23")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "6.02e-23" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "6.02e-23")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -466,9 +460,8 @@ TEST(DoubleLogFormatTest, Positive) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("6.02e+23")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "6.02e+23" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "6.02e+23")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -484,9 +477,8 @@ TEST(DoubleLogFormatTest, Negative) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("-6.02e+23")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "-6.02e+23" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "-6.02e+23")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -502,9 +494,8 @@ TEST(DoubleLogFormatTest, NegativeExponent) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("6.02e-23")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "6.02e-23" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "6.02e-23")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -522,11 +513,11 @@ TYPED_TEST(FloatingPointLogFormatTest, Zero) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("0")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "0" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("0")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "0")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -539,11 +530,11 @@ TYPED_TEST(FloatingPointLogFormatTest, Integer) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("1")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "1" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("1")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "1")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -556,11 +547,11 @@ TYPED_TEST(FloatingPointLogFormatTest, Infinity) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(AnyOf(Eq("inf"), Eq("Inf"))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "inf" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(AnyOf(Eq("inf"), Eq("Inf"))), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "inf")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -573,12 +564,11 @@ TYPED_TEST(FloatingPointLogFormatTest, NegativeInfinity) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(AnyOf(Eq("-inf"), Eq("-Inf"))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "-inf" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(AnyOf(Eq("-inf"), Eq("-Inf"))), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "-inf")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -591,11 +581,11 @@ TYPED_TEST(FloatingPointLogFormatTest, NaN) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(AnyOf(Eq("nan"), Eq("NaN"))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "nan" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(AnyOf(Eq("nan"), Eq("NaN"))), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "nan")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; } @@ -608,15 +598,29 @@ TYPED_TEST(FloatingPointLogFormatTest, NegativeNaN) { auto comparison_stream = ComparisonStream(); comparison_stream << value; + // On RISC-V, don't expect that formatting -NaN produces the same string as + // streaming it. #ifdefing out just the relevant line breaks the MSVC build, + // so duplicate the entire EXPECT_CALL. +#ifdef __riscv + EXPECT_CALL( + test_sink, + Send(AllOf( + TextMessage(AnyOf(Eq("-nan"), Eq("nan"), Eq("NaN"), Eq("-nan(ind)"))), + ENCODED_MESSAGE(HasValues( + ElementsAre(AnyOf(EqualsProto(R"pb(str: "-nan")pb"), + EqualsProto(R"pb(str: "nan")pb"), + EqualsProto(R"pb(str: "-nan(ind)")pb")))))))); +#else EXPECT_CALL( test_sink, Send(AllOf( TextMessage(MatchesOstream(comparison_stream)), TextMessage(AnyOf(Eq("-nan"), Eq("nan"), Eq("NaN"), Eq("-nan(ind)"))), - ENCODED_MESSAGE( - AnyOf(EqualsProto(R"pb(value { str: "-nan" })pb"), - EqualsProto(R"pb(value { str: "nan" })pb"), - EqualsProto(R"pb(value { str: "-nan(ind)" })pb")))))); + ENCODED_MESSAGE(HasValues( + ElementsAre(AnyOf(EqualsProto(R"pb(str: "-nan")pb"), + EqualsProto(R"pb(str: "nan")pb"), + EqualsProto(R"pb(str: "-nan(ind)")pb")))))))); +#endif test_sink.StartCapturingLogs(); LOG(INFO) << value; } @@ -652,13 +656,12 @@ TYPED_TEST(VoidPtrLogFormatTest, NonNull) { EXPECT_CALL( test_sink, - Send(AllOf( - TextMessage(MatchesOstream(comparison_stream)), - TextMessage( - AnyOf(Eq("0xdeadbeef"), Eq("DEADBEEF"), Eq("00000000DEADBEEF"))), - ENCODED_MESSAGE(AnyOf( - EqualsProto(R"pb(value { str: "0xdeadbeef" })pb"), - EqualsProto(R"pb(value { str: "00000000DEADBEEF" })pb")))))); + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(AnyOf(Eq("0xdeadbeef"), Eq("DEADBEEF"), + Eq("00000000DEADBEEF"))), + ENCODED_MESSAGE(HasValues(ElementsAre( + AnyOf(EqualsProto(R"pb(str: "0xdeadbeef")pb"), + EqualsProto(R"pb(str: "00000000DEADBEEF")pb")))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -680,12 +683,11 @@ TYPED_TEST(VolatilePtrLogFormatTest, Null) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("false")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "false" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("false")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "false")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -698,12 +700,11 @@ TYPED_TEST(VolatilePtrLogFormatTest, NonNull) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("true")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "true" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("true")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "true")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -729,7 +730,8 @@ TYPED_TEST(CharPtrLogFormatTest, Null) { Send(AllOf( // `MatchesOstream` deliberately omitted since we deliberately differ. TextMessage(Eq("(null)")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "(null)" })pb"))))); + ENCODED_MESSAGE( + HasValues(ElementsAre(EqualsProto(R"pb(str: "(null)")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -743,12 +745,11 @@ TYPED_TEST(CharPtrLogFormatTest, NonNull) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("value")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "value" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("value")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "value")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -761,12 +762,11 @@ TEST(BoolLogFormatTest, True) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("true")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "true" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("true")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "true")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -779,12 +779,11 @@ TEST(BoolLogFormatTest, False) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("false")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "false" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("false")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "false")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -799,9 +798,8 @@ TEST(LogFormatTest, StringLiteral) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("value")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - literal: "value" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(literal: "value")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << "value"; @@ -814,12 +812,11 @@ TEST(LogFormatTest, CharArray) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("value")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "value" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("value")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "value")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -840,9 +837,8 @@ TEST(LogFormatTest, Custom) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("CustomClass{}")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "CustomClass{}" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "CustomClass{}")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; } @@ -864,12 +860,11 @@ TEST(LogFormatTest, CustomNonCopyable) { auto comparison_stream = ComparisonStream(); comparison_stream << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("CustomClassNonCopyable{}")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { str: "CustomClassNonCopyable{}" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("CustomClassNonCopyable{}")), + ENCODED_MESSAGE(HasValues(ElementsAre(EqualsProto( + R"pb(str: "CustomClassNonCopyable{}")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value; @@ -892,9 +887,9 @@ TEST(LogFormatTest, AbslStringifyExample) { EXPECT_CALL( test_sink, - Send(AllOf( - TextMessage(Eq("(10, 20)")), TextMessage(Eq(absl::StrCat(p))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "(10, 20)" })pb"))))); + Send(AllOf(TextMessage(Eq("(10, 20)")), TextMessage(Eq(absl::StrCat(p))), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "(10, 20)")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << p; @@ -923,9 +918,9 @@ TEST(LogFormatTest, CustomWithAbslStringifyAndOstream) { EXPECT_CALL( test_sink, - Send(AllOf( - TextMessage(Eq("(10, 20)")), TextMessage(Eq(absl::StrCat(p))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "(10, 20)" })pb"))))); + Send(AllOf(TextMessage(Eq("(10, 20)")), TextMessage(Eq(absl::StrCat(p))), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "(10, 20)")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << p; @@ -944,10 +939,10 @@ TEST(LogFormatTest, AbslStringifyStreamsNothing) { PointStreamsNothing p; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(Eq("77")), TextMessage(Eq(absl::StrCat(p, 77))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "77" })pb"))))); + EXPECT_CALL(test_sink, Send(AllOf(TextMessage(Eq("77")), + TextMessage(Eq(absl::StrCat(p, 77))), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << p << 77; @@ -971,10 +966,10 @@ TEST(LogFormatTest, AbslStringifyMultipleAppend) { EXPECT_CALL( test_sink, - Send(AllOf( - TextMessage(Eq("(10, 20)")), TextMessage(Eq(absl::StrCat(p))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "(" } - value { str: "10, 20)" })pb"))))); + Send(AllOf(TextMessage(Eq("(10, 20)")), TextMessage(Eq(absl::StrCat(p))), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "(")pb"), + EqualsProto(R"pb(str: "10, 20)")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << p; @@ -992,12 +987,12 @@ TEST(ManipulatorLogFormatTest, BoolAlphaTrue) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("1 true 1")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { str: "1" } - value { literal: " " } - value { str: "true" } - value { literal: " " } - value { str: "1" })pb"))))); + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "1")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "true")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "1")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::noboolalpha << value << " " // @@ -1017,12 +1012,12 @@ TEST(ManipulatorLogFormatTest, BoolAlphaFalse) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("0 false 0")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { str: "0" } - value { literal: " " } - value { str: "false" } - value { literal: " " } - value { str: "0" })pb"))))); + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "0")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "false")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "0")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::noboolalpha << value << " " // @@ -1039,15 +1034,15 @@ TEST(ManipulatorLogFormatTest, ShowPoint) { << std::showpoint << value << " " // << std::noshowpoint << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("77 77.0000 77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "77" } - value { literal: " " } - value { str: "77.0000" } - value { literal: " " } - value { str: "77" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("77 77.0000 77")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "77")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "77.0000")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::noshowpoint << value << " " // @@ -1064,15 +1059,15 @@ TEST(ManipulatorLogFormatTest, ShowPos) { << std::showpos << value << " " // << std::noshowpos << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("77 +77 77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "77" } - value { literal: " " } - value { str: "+77" } - value { literal: " " } - value { str: "77" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("77 +77 77")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "77")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "+77")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::noshowpos << value << " " // @@ -1092,12 +1087,12 @@ TEST(ManipulatorLogFormatTest, UppercaseFloat) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("7.7e+07 7.7E+07 7.7e+07")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { str: "7.7e+07" } - value { literal: " " } - value { str: "7.7E+07" } - value { literal: " " } - value { str: "7.7e+07" })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "7.7e+07")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "7.7E+07")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "7.7e+07")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::nouppercase << value << " " // @@ -1112,12 +1107,11 @@ TEST(ManipulatorLogFormatTest, Hex) { auto comparison_stream = ComparisonStream(); comparison_stream << std::hex << value; - EXPECT_CALL( - test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("0x77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "0x77" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("0x77")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "0x77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::hex << value; } @@ -1129,11 +1123,11 @@ TEST(ManipulatorLogFormatTest, Oct) { auto comparison_stream = ComparisonStream(); comparison_stream << std::oct << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("077")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "077" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("077")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "077")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::oct << value; @@ -1146,11 +1140,11 @@ TEST(ManipulatorLogFormatTest, Dec) { auto comparison_stream = ComparisonStream(); comparison_stream << std::hex << std::dec << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "77" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("77")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::hex << std::dec << value; @@ -1166,15 +1160,15 @@ TEST(ManipulatorLogFormatTest, ShowbaseHex) { << std::showbase << value << " " // << std::noshowbase << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("77 0x77 77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "77" } - value { literal: " " } - value { str: "0x77" } - value { literal: " " } - value { str: "77" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("77 0x77 77")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "77")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "0x77")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::hex // @@ -1193,15 +1187,15 @@ TEST(ManipulatorLogFormatTest, ShowbaseOct) { << std::showbase << value << " " // << std::noshowbase << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("77 077 77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "77" } - value { literal: " " } - value { str: "077" } - value { literal: " " } - value { str: "77" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("77 077 77")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "77")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "077")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::oct // @@ -1224,12 +1218,12 @@ TEST(ManipulatorLogFormatTest, UppercaseHex) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("0xbeef 0XBEEF 0xbeef")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { str: "0xbeef" } - value { literal: " " } - value { str: "0XBEEF" } - value { literal: " " } - value { str: "0xbeef" })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "0xbeef")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "0XBEEF")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "0xbeef")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::hex // @@ -1245,13 +1239,11 @@ TEST(ManipulatorLogFormatTest, FixedFloat) { auto comparison_stream = ComparisonStream(); comparison_stream << std::fixed << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("77000000.000000")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "77000000.000000" - })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("77000000.000000")), + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "77000000.000000")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::fixed << value; @@ -1267,9 +1259,8 @@ TEST(ManipulatorLogFormatTest, ScientificFloat) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("7.700000e+07")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "7.700000e+07" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "7.700000e+07")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::scientific << value; @@ -1295,11 +1286,9 @@ TEST(ManipulatorLogFormatTest, FixedAndScientificFloat) { Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(AnyOf(Eq("0x1.25bb50p+26"), Eq("0x1.25bb5p+26"), Eq("0x1.25bb500000000p+26"))), - ENCODED_MESSAGE( - AnyOf(EqualsProto(R"pb(value { str: "0x1.25bb5p+26" })pb"), - EqualsProto(R"pb(value { - str: "0x1.25bb500000000p+26" - })pb")))))); + ENCODED_MESSAGE(HasValues(ElementsAre(AnyOf( + EqualsProto(R"pb(str: "0x1.25bb5p+26")pb"), + EqualsProto(R"pb(str: "0x1.25bb500000000p+26")pb")))))))); test_sink.StartCapturingLogs(); @@ -1328,11 +1317,9 @@ TEST(ManipulatorLogFormatTest, HexfloatFloat) { Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(AnyOf(Eq("0x1.25bb50p+26"), Eq("0x1.25bb5p+26"), Eq("0x1.25bb500000000p+26"))), - ENCODED_MESSAGE( - AnyOf(EqualsProto(R"pb(value { str: "0x1.25bb5p+26" })pb"), - EqualsProto(R"pb(value { - str: "0x1.25bb500000000p+26" - })pb")))))); + ENCODED_MESSAGE(HasValues(ElementsAre(AnyOf( + EqualsProto(R"pb(str: "0x1.25bb5p+26")pb"), + EqualsProto(R"pb(str: "0x1.25bb500000000p+26")pb")))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::hexfloat << value; @@ -1349,9 +1336,8 @@ TEST(ManipulatorLogFormatTest, DefaultFloatFloat) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("7.7e+07")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "7.7e+07" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "7.7e+07")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::hexfloat << std::defaultfloat << value; @@ -1363,11 +1349,11 @@ TEST(ManipulatorLogFormatTest, Ends) { auto comparison_stream = ComparisonStream(); comparison_stream << std::ends; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq(absl::string_view("\0", 1))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "\0" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq(absl::string_view("\0", 1))), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "\0")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::ends; @@ -1384,7 +1370,8 @@ TEST(ManipulatorLogFormatTest, Endl) { Send(AllOf( TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("\n")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "\n" })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre(EqualsProto(R"pb(str: + "\n")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::endl; @@ -1408,10 +1395,10 @@ TEST(ManipulatorLogFormatTest, SetIosFlags) { // `std::setiosflags` and `std::resetiosflags` aren't manipulators. // We're unable to distinguish their return type(s) from arbitrary // user-defined types and thus don't suppress the empty str value. - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "0x77" } - value { literal: " " } - value { str: "119" } - )pb"))))); + ENCODED_MESSAGE( + HasValues(ElementsAre(EqualsProto(R"pb(str: "0x77")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "119")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::resetiosflags(std::ios_base::basefield) @@ -1435,10 +1422,10 @@ TEST(ManipulatorLogFormatTest, SetBase) { // `std::setbase` isn't a manipulator. We're unable to // distinguish its return type from arbitrary user-defined // types and thus don't suppress the empty str value. - ENCODED_MESSAGE(EqualsProto( - R"pb(value { str: "0x77" } - value { literal: " " } - value { str: "119" })pb"))))); + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "0x77")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "119")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::setbase(16) << value << " " // @@ -1454,13 +1441,13 @@ TEST(ManipulatorLogFormatTest, SetPrecision) { EXPECT_CALL( test_sink, - Send(AllOf( - TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("6.022e+23")), - // `std::setprecision` isn't a manipulator. We're unable to - // distinguish its return type from arbitrary user-defined - // types and thus don't suppress the empty str value. - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "6.022e+23" })pb"))))); + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("6.022e+23")), + // `std::setprecision` isn't a manipulator. We're unable to + // distinguish its return type from arbitrary user-defined + // types and thus don't suppress the empty str value. + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "6.022e+23")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::setprecision(4) << value; @@ -1473,12 +1460,11 @@ TEST(ManipulatorLogFormatTest, SetPrecisionOverflow) { auto comparison_stream = ComparisonStream(); comparison_stream << std::setprecision(200) << value; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("602214085700000015187968")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { str: "602214085700000015187968" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("602214085700000015187968")), + ENCODED_MESSAGE(HasValues(ElementsAre(EqualsProto( + R"pb(str: "602214085700000015187968")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::setprecision(200) << value; @@ -1493,13 +1479,13 @@ TEST(ManipulatorLogFormatTest, SetW) { EXPECT_CALL( test_sink, - Send(AllOf( - TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq(" 77")), - // `std::setw` isn't a manipulator. We're unable to - // distinguish its return type from arbitrary user-defined - // types and thus don't suppress the empty str value. - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: " 77" })pb"))))); + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq(" 77")), + // `std::setw` isn't a manipulator. We're unable to + // distinguish its return type from arbitrary user-defined + // types and thus don't suppress the empty str value. + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: " 77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::setw(8) << value; @@ -1515,9 +1501,8 @@ TEST(ManipulatorLogFormatTest, Left) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("-77 ")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "-77 " - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "-77 ")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::left << std::setw(8) << value; @@ -1533,9 +1518,8 @@ TEST(ManipulatorLogFormatTest, Right) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq(" -77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: " -77" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: " -77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::right << std::setw(8) << value; @@ -1551,9 +1535,8 @@ TEST(ManipulatorLogFormatTest, Internal) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("- 77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "- 77" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "- 77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::internal << std::setw(8) << value; @@ -1573,9 +1556,8 @@ TEST(ManipulatorLogFormatTest, SetFill) { // unable to distinguish its return // type from arbitrary user-defined types and // thus don't suppress the empty str value. - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "00000077" - })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "00000077")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::setfill('0') << std::setw(8) << value; @@ -1596,10 +1578,10 @@ TEST(ManipulatorLogFormatTest, FromCustom) { EXPECT_CALL(test_sink, Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), TextMessage(Eq("FromCustomClass{} 0x77")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { str: "FromCustomClass{}" } - value { literal: " " } - value { str: "0x77" })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(str: "FromCustomClass{}")pb"), + EqualsProto(R"pb(literal: " ")pb"), + EqualsProto(R"pb(str: "0x77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value << " " << 0x77; @@ -1615,11 +1597,11 @@ TEST(ManipulatorLogFormatTest, CustomClassStreamsNothing) { auto comparison_stream = ComparisonStream(); comparison_stream << value << 77; - EXPECT_CALL( - test_sink, - Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), - TextMessage(Eq("77")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "77" })pb"))))); + EXPECT_CALL(test_sink, + Send(AllOf(TextMessage(MatchesOstream(comparison_stream)), + TextMessage(Eq("77")), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "77")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << value << 77; @@ -1642,9 +1624,9 @@ TEST(ManipulatorLogFormatTest, IOManipsDoNotAffectAbslStringify) { EXPECT_CALL( test_sink, - Send(AllOf( - TextMessage(Eq("(10, 20)")), TextMessage(Eq(absl::StrCat(p))), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "(10, 20)" })pb"))))); + Send(AllOf(TextMessage(Eq("(10, 20)")), TextMessage(Eq(absl::StrCat(p))), + ENCODED_MESSAGE(HasValues( + ElementsAre(EqualsProto(R"pb(str: "(10, 20)")pb"))))))); test_sink.StartCapturingLogs(); LOG(INFO) << std::hex << p; diff --git a/absl/log/log_modifier_methods_test.cc b/absl/log/log_modifier_methods_test.cc index 42e13b1b..4ccde404 100644 --- a/absl/log/log_modifier_methods_test.cc +++ b/absl/log/log_modifier_methods_test.cc @@ -156,9 +156,11 @@ TEST(TailCallsModifiesTest, WithMetadataFrom) { Timestamp(Eq(absl::UnixEpoch())), ThreadID(Eq(absl::LogEntry::tid_t{456})), TextMessage(Eq("forwarded: hello world")), Verbosity(Eq(7)), - ENCODED_MESSAGE( - EqualsProto(R"pb(value { literal: "forwarded: " } - value { str: "hello world" })pb"))))); + ENCODED_MESSAGE(MatchesEvent( + Eq("fake/file"), Eq(123), Eq(absl::UnixEpoch()), + Eq(logging::proto::WARNING), Eq(456), + ElementsAre(EqualsProto(R"pb(literal: "forwarded: ")pb"), + EqualsProto(R"pb(str: "hello world")pb"))))))); test_sink.StartCapturingLogs(); LOG(WARNING) @@ -179,25 +181,15 @@ TEST(TailCallsModifiesTest, WithPerror) { Send(AllOf(TextMessage(AnyOf(Eq("hello world: Bad file number [9]"), Eq("hello world: Bad file descriptor [9]"), Eq("hello world: Bad file descriptor [8]"))), - ENCODED_MESSAGE( - AnyOf(EqualsProto(R"pb(value { literal: "hello world" } - value { literal: ": " } - value { str: "Bad file number" } - value { literal: " [" } - value { str: "9" } - value { literal: "]" })pb"), - EqualsProto(R"pb(value { literal: "hello world" } - value { literal: ": " } - value { str: "Bad file descriptor" } - value { literal: " [" } - value { str: "9" } - value { literal: "]" })pb"), - EqualsProto(R"pb(value { literal: "hello world" } - value { literal: ": " } - value { str: "Bad file descriptor" } - value { literal: " [" } - value { str: "8" } - value { literal: "]" })pb")))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(literal: "hello world")pb"), + EqualsProto(R"pb(literal: ": ")pb"), + AnyOf(EqualsProto(R"pb(str: "Bad file number")pb"), + EqualsProto(R"pb(str: "Bad file descriptor")pb")), + EqualsProto(R"pb(literal: " [")pb"), + AnyOf(EqualsProto(R"pb(str: "8")pb"), + EqualsProto(R"pb(str: "9")pb")), + EqualsProto(R"pb(literal: "]")pb"))))))); test_sink.StartCapturingLogs(); errno = EBADF; diff --git a/absl/log/log_sink.h b/absl/log/log_sink.h index 9bfa6f86..2910070d 100644 --- a/absl/log/log_sink.h +++ b/absl/log/log_sink.h @@ -32,15 +32,16 @@ ABSL_NAMESPACE_BEGIN // `absl::LogSink` is an interface which can be extended to intercept and // process particular messages (with `LOG.ToSinkOnly()` or // `LOG.ToSinkAlso()`) or all messages (if registered with -// `absl::AddLogSink`). Implementations must be thread-safe, and should take -// care not to take any locks that might be held by the `LOG` caller. +// `absl::AddLogSink`). Implementations must not take any locks that might be +// held by the `LOG` caller. class LogSink { public: virtual ~LogSink() = default; // LogSink::Send() // - // `Send` is called synchronously during the log statement. + // `Send` is called synchronously during the log statement. `Send` must be + // thread-safe. // // It is safe to use `LOG` within an implementation of `Send`. `ToSinkOnly` // and `ToSinkAlso` are safe in general but can be used to create an infinite @@ -50,9 +51,15 @@ class LogSink { // LogSink::Flush() // // Sinks that buffer messages should override this method to flush the buffer - // and return. + // and return. `Flush` must be thread-safe. virtual void Flush() {} + protected: + LogSink() = default; + // Implementations may be copyable and/or movable. + LogSink(const LogSink&) = default; + LogSink& operator=(const LogSink&) = default; + private: // https://lld.llvm.org/missingkeyfunction.html#missing-key-function virtual void KeyFunction() const final; // NOLINT(readability/inheritance) diff --git a/absl/log/log_streamer_test.cc b/absl/log/log_streamer_test.cc index 40c7d488..b9b94282 100644 --- a/absl/log/log_streamer_test.cc +++ b/absl/log/log_streamer_test.cc @@ -38,6 +38,7 @@ using ::absl::log_internal::DeathTestValidateExpectations; #if GTEST_HAS_DEATH_TEST using ::absl::log_internal::DiedOfFatal; #endif +using ::absl::log_internal::InMatchWindow; using ::absl::log_internal::LogSeverity; using ::absl::log_internal::Prefix; using ::absl::log_internal::SourceFilename; @@ -45,7 +46,8 @@ using ::absl::log_internal::SourceLine; using ::absl::log_internal::Stacktrace; using ::absl::log_internal::TextMessage; using ::absl::log_internal::ThreadID; -using ::absl::log_internal::TimestampInMatchWindow; +using ::absl::log_internal::Timestamp; +using ::testing::_; using ::testing::AnyNumber; using ::testing::Eq; using ::testing::HasSubstr; @@ -67,15 +69,17 @@ TEST(LogStreamerTest, LogInfoStreamer) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kInfo)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("WriteToStream: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStream: foo" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kInfo)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("WriteToStream: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), InMatchWindow(), + Eq(logging::proto::INFO), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); WriteToStream("foo", &absl::LogInfoStreamer("path/file.cc", 1234).stream()); @@ -86,15 +90,17 @@ TEST(LogStreamerTest, LogWarningStreamer) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kWarning)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("WriteToStream: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStream: foo" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kWarning)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("WriteToStream: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), InMatchWindow(), + Eq(logging::proto::WARNING), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); WriteToStream("foo", @@ -106,15 +112,17 @@ TEST(LogStreamerTest, LogErrorStreamer) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("WriteToStream: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStream: foo" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("WriteToStream: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), InMatchWindow(), + Eq(logging::proto::ERROR), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); WriteToStream("foo", &absl::LogErrorStreamer("path/file.cc", 1234).stream()); @@ -130,17 +138,19 @@ TEST(LogStreamerDeathTest, LogFatalStreamer) { .Times(AnyNumber()) .WillRepeatedly(DeathTestUnexpectedLogging()); - EXPECT_CALL( - test_sink, - Send(AllOf( - SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("WriteToStream: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStream: foo" - })pb"))))) + EXPECT_CALL(test_sink, + Send(AllOf(SourceFilename(Eq("path/file.cc")), + SourceLine(Eq(1234)), Prefix(IsTrue()), + LogSeverity(Eq(absl::LogSeverity::kFatal)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("WriteToStream: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), + InMatchWindow(), Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(str: "WriteToStream: foo")pb"))))))) .WillOnce(DeathTestExpectedLogging()); test_sink.StartCapturingLogs(); @@ -157,15 +167,17 @@ TEST(LogStreamerTest, LogDebugFatalStreamer) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("WriteToStream: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStream: foo" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("WriteToStream: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), InMatchWindow(), + Eq(logging::proto::ERROR), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); WriteToStream("foo", @@ -181,17 +193,19 @@ TEST(LogStreamerDeathTest, LogDebugFatalStreamer) { .Times(AnyNumber()) .WillRepeatedly(DeathTestUnexpectedLogging()); - EXPECT_CALL( - test_sink, - Send(AllOf( - SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("WriteToStream: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStream: foo" - })pb"))))) + EXPECT_CALL(test_sink, + Send(AllOf(SourceFilename(Eq("path/file.cc")), + SourceLine(Eq(1234)), Prefix(IsTrue()), + LogSeverity(Eq(absl::LogSeverity::kFatal)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("WriteToStream: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), + InMatchWindow(), Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(str: "WriteToStream: foo")pb"))))))) .WillOnce(DeathTestExpectedLogging()); test_sink.StartCapturingLogs(); @@ -207,15 +221,17 @@ TEST(LogStreamerTest, LogStreamer) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("WriteToStream: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStream: foo" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("WriteToStream: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), InMatchWindow(), + Eq(logging::proto::ERROR), Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); WriteToStream( @@ -233,17 +249,19 @@ TEST(LogStreamerDeathTest, LogStreamer) { .Times(AnyNumber()) .WillRepeatedly(DeathTestUnexpectedLogging()); - EXPECT_CALL( - test_sink, - Send(AllOf( - SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kFatal)), - TimestampInMatchWindow(), - ThreadID(Eq(absl::base_internal::GetTID())), - TextMessage(Eq("WriteToStream: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStream: foo" - })pb"))))) + EXPECT_CALL(test_sink, + Send(AllOf(SourceFilename(Eq("path/file.cc")), + SourceLine(Eq(1234)), Prefix(IsTrue()), + LogSeverity(Eq(absl::LogSeverity::kFatal)), + Timestamp(InMatchWindow()), + ThreadID(Eq(absl::base_internal::GetTID())), + TextMessage(Eq("WriteToStream: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), + InMatchWindow(), Eq(logging::proto::FATAL), + Eq(absl::base_internal::GetTID()), + ElementsAre(EqualsProto( + R"pb(str: "WriteToStream: foo")pb"))))))) .WillOnce(DeathTestExpectedLogging()); test_sink.StartCapturingLogs(); @@ -260,12 +278,13 @@ TEST(LogStreamerTest, PassedByReference) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - TextMessage(Eq("WriteToStreamRef: foo")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "WriteToStreamRef: foo" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + TextMessage(Eq("WriteToStreamRef: foo")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), _, _, _, + ElementsAre(EqualsProto(R"pb(str: "WriteToStreamRef: foo")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); WriteToStreamRef("foo", absl::LogInfoStreamer("path/file.cc", 1234).stream()); @@ -284,13 +303,14 @@ TEST(LogStreamerTest, StoredAsLocal) { // test would fail. EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - TextMessage(Eq("WriteToStream: foo WriteToStreamRef: bar")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { - str: "WriteToStream: foo WriteToStreamRef: bar" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + TextMessage(Eq("WriteToStream: foo WriteToStreamRef: bar")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), _, _, _, + ElementsAre(EqualsProto( + R"pb(str: "WriteToStream: foo WriteToStreamRef: bar")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); } @@ -311,12 +331,13 @@ TEST(LogStreamerDeathTest, StoredAsLocal) { TEST(LogStreamerTest, LogsEmptyLine) { absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected); - EXPECT_CALL(test_sink, Send(AllOf(SourceFilename(Eq("path/file.cc")), - SourceLine(Eq(1234)), TextMessage(Eq("")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "" - })pb")), - Stacktrace(IsEmpty())))); + EXPECT_CALL(test_sink, + Send(AllOf(SourceFilename(Eq("path/file.cc")), + SourceLine(Eq(1234)), TextMessage(Eq("")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), _, _, _, + ElementsAre(EqualsProto(R"pb(str: "")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); absl::LogInfoStreamer("path/file.cc", 1234); @@ -334,9 +355,10 @@ TEST(LogStreamerDeathTest, LogsEmptyLine) { EXPECT_CALL( test_sink, - Send(AllOf( - SourceFilename(Eq("path/file.cc")), TextMessage(Eq("")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { str: "" })pb"))))) + Send(AllOf(SourceFilename(Eq("path/file.cc")), TextMessage(Eq("")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), _, _, _, _, + ElementsAre(EqualsProto(R"pb(str: "")pb"))))))) .WillOnce(DeathTestExpectedLogging()); test_sink.StartCapturingLogs(); @@ -352,13 +374,14 @@ TEST(LogStreamerTest, MoveConstruction) { EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - LogSeverity(Eq(absl::LogSeverity::kInfo)), - TextMessage(Eq("hello 0x10 world 0x10")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "hello 0x10 world 0x10" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + LogSeverity(Eq(absl::LogSeverity::kInfo)), + TextMessage(Eq("hello 0x10 world 0x10")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), _, Eq(logging::proto::INFO), _, + ElementsAre(EqualsProto(R"pb(str: "hello 0x10 world 0x10")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); auto streamer1 = absl::LogInfoStreamer("path/file.cc", 1234); @@ -373,22 +396,24 @@ TEST(LogStreamerTest, MoveAssignment) { testing::InSequence seq; EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file2.cc")), SourceLine(Eq(5678)), - LogSeverity(Eq(absl::LogSeverity::kWarning)), - TextMessage(Eq("something else")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "something else" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file2.cc")), SourceLine(Eq(5678)), + LogSeverity(Eq(absl::LogSeverity::kWarning)), + TextMessage(Eq("something else")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file2.cc"), Eq(5678), _, Eq(logging::proto::WARNING), _, + ElementsAre(EqualsProto(R"pb(str: "something else")pb")))), + Stacktrace(IsEmpty())))); EXPECT_CALL( test_sink, - Send(AllOf(SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), - LogSeverity(Eq(absl::LogSeverity::kInfo)), - TextMessage(Eq("hello 0x10 world 0x10")), - ENCODED_MESSAGE(EqualsProto(R"pb(value { - str: "hello 0x10 world 0x10" - })pb")), - Stacktrace(IsEmpty())))); + Send(AllOf( + SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)), + LogSeverity(Eq(absl::LogSeverity::kInfo)), + TextMessage(Eq("hello 0x10 world 0x10")), + ENCODED_MESSAGE(MatchesEvent( + Eq("path/file.cc"), Eq(1234), _, Eq(logging::proto::INFO), _, + ElementsAre(EqualsProto(R"pb(str: "hello 0x10 world 0x10")pb")))), + Stacktrace(IsEmpty())))); test_sink.StartCapturingLogs(); auto streamer1 = absl::LogInfoStreamer("path/file.cc", 1234); diff --git a/absl/log/structured_test.cc b/absl/log/structured_test.cc index 490a35d8..6f1df186 100644 --- a/absl/log/structured_test.cc +++ b/absl/log/structured_test.cc @@ -30,6 +30,7 @@ namespace { using ::absl::log_internal::MatchesOstream; using ::absl::log_internal::TextMessage; +using ::testing::ElementsAre; using ::testing::Eq; auto *test_env ABSL_ATTRIBUTE_UNUSED = ::testing::AddGlobalTestEnvironment( @@ -53,8 +54,8 @@ TEST(StreamingFormatTest, LogAsLiteral) { EXPECT_CALL(sink, Send(AllOf(TextMessage(MatchesOstream(stream)), TextMessage(Eq("hello world")), - ENCODED_MESSAGE(EqualsProto( - R"pb(value { literal: "hello world" })pb"))))); + ENCODED_MESSAGE(HasValues(ElementsAre( + EqualsProto(R"pb(literal: "hello world")pb"))))))); sink.StartCapturingLogs(); LOG(INFO) << absl::LogAsLiteral(not_a_literal); diff --git a/absl/log/vlog_is_on.h b/absl/log/vlog_is_on.h index 78986513..f7539df4 100644 --- a/absl/log/vlog_is_on.h +++ b/absl/log/vlog_is_on.h @@ -46,12 +46,12 @@ // Files which do not match any pattern in `--vmodule` use the value of `--v` as // their effective verbosity level. The default is 0. // -// SetVLOGLevel helper function is provided to do limited dynamic control over +// SetVLogLevel helper function is provided to do limited dynamic control over // V-logging by appending to `--vmodule`. Because these go at the beginning of // the list, they take priority over any globs previously added. // // Resetting --vmodule will override all previous modifications to `--vmodule`, -// including via SetVLOGLevel. +// including via SetVLogLevel. #ifndef ABSL_LOG_VLOG_IS_ON_H_ #define ABSL_LOG_VLOG_IS_ON_H_ @@ -63,7 +63,7 @@ // Each VLOG_IS_ON call site gets its own VLogSite that registers with the // global linked list of sites to asynchronously update its verbosity level on // changes to --v or --vmodule. The verbosity can also be set by manually -// calling SetVLOGLevel. +// calling SetVLogLevel. // // VLOG_IS_ON is not async signal safe, but it is guaranteed not to allocate // new memory. |