Commit 9a7e8e36 by Andy Getzendanner Committed by Copybara-Service

Zero encoded_remaining when a string field doesn't fit, so that we don't leave…

Zero encoded_remaining when a string field doesn't fit, so that we don't leave partial data in the buffer (all decoders should ignore it anyway) and to be sure that we don't try to put any subsequent operands in either (there shouldn't be enough space).

PiperOrigin-RevId: 490143656
Change-Id: I4d743dd9214013fbd151478ef662d50affd5ff7a
parent d081b629
...@@ -332,6 +332,7 @@ cc_test( ...@@ -332,6 +332,7 @@ cc_test(
copts = ABSL_TEST_COPTS, copts = ABSL_TEST_COPTS,
linkopts = ABSL_DEFAULT_LINKOPTS, linkopts = ABSL_DEFAULT_LINKOPTS,
deps = [ deps = [
":check",
":log", ":log",
":scoped_mock_log", ":scoped_mock_log",
"//absl/log/internal:test_matchers", "//absl/log/internal:test_matchers",
......
...@@ -745,6 +745,7 @@ absl_cc_test( ...@@ -745,6 +745,7 @@ absl_cc_test(
LINKOPTS LINKOPTS
${ABSL_DEFAULT_LINKOPTS} ${ABSL_DEFAULT_LINKOPTS}
DEPS DEPS
absl::check
absl::log absl::log
absl::log_internal_test_matchers absl::log_internal_test_matchers
absl::scoped_mock_log absl::scoped_mock_log
......
...@@ -345,11 +345,13 @@ void LogMessage::FailQuietly() { ...@@ -345,11 +345,13 @@ void LogMessage::FailQuietly() {
} }
LogMessage& LogMessage::operator<<(const std::string& v) { LogMessage& LogMessage::operator<<(const std::string& v) {
return LogString(false, v); CopyToEncodedBuffer(v, StringType::kNotLiteral);
return *this;
} }
LogMessage& LogMessage::operator<<(absl::string_view v) { LogMessage& LogMessage::operator<<(absl::string_view v) {
return LogString(false, v); CopyToEncodedBuffer(v, StringType::kNotLiteral);
return *this;
} }
LogMessage& LogMessage::operator<<(std::ostream& (*m)(std::ostream& os)) { LogMessage& LogMessage::operator<<(std::ostream& (*m)(std::ostream& os)) {
OstreamView view(*data_); OstreamView view(*data_);
...@@ -424,27 +426,28 @@ LogMessage::OstreamView::OstreamView(LogMessageData& message_data) ...@@ -424,27 +426,28 @@ LogMessage::OstreamView::OstreamView(LogMessageData& message_data)
&encoded_remaining_copy_); &encoded_remaining_copy_);
string_start_ = string_start_ =
EncodeMessageStart(ValueTag::kString, encoded_remaining_copy_.size(), EncodeMessageStart(ValueTag::kString, encoded_remaining_copy_.size(),
&encoded_remaining_copy_); &encoded_remaining_copy_);
setp(encoded_remaining_copy_.data(), setp(encoded_remaining_copy_.data(),
encoded_remaining_copy_.data() + encoded_remaining_copy_.size()); encoded_remaining_copy_.data() + encoded_remaining_copy_.size());
data_.manipulated.rdbuf(this); data_.manipulated.rdbuf(this);
} }
LogMessage::OstreamView::~OstreamView() { LogMessage::OstreamView::~OstreamView() {
const absl::Span<const char> contents(pbase(), data_.manipulated.rdbuf(nullptr);
static_cast<size_t>(pptr() - pbase()));
encoded_remaining_copy_.remove_prefix(contents.size());
if (!string_start_.data()) { if (!string_start_.data()) {
// The headers didn't fit; we won't write anything to the buffer, but we // The second field header didn't fit. Whether the first one did or not, we
// also need to zero the size of `data_->encoded_remaining` so that no more // shouldn't commit `encoded_remaining_copy_`, and we also need to zero the
// data is encoded. // size of `data_->encoded_remaining` so that no more data are encoded.
data_.encoded_remaining.remove_suffix(data_.encoded_remaining.size()); data_.encoded_remaining.remove_suffix(data_.encoded_remaining.size());
} else if (!contents.empty()) { return;
EncodeMessageLength(string_start_, &encoded_remaining_copy_);
EncodeMessageLength(message_start_, &encoded_remaining_copy_);
data_.encoded_remaining = encoded_remaining_copy_;
} }
data_.manipulated.rdbuf(nullptr); const absl::Span<const char> contents(pbase(),
static_cast<size_t>(pptr() - pbase()));
if (contents.empty()) return;
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_;
} }
std::ostream& LogMessage::OstreamView::stream() { return data_.manipulated; } std::ostream& LogMessage::OstreamView::stream() { return data_.manipulated; }
...@@ -511,21 +514,31 @@ void LogMessage::LogBacktraceIfNeeded() { ...@@ -511,21 +514,31 @@ void LogMessage::LogBacktraceIfNeeded() {
view.stream() << ") "; view.stream() << ") ";
} }
// Encodes a partial `logging.proto.Event` containing the specified string data // Encodes into `data_->encoded_remaining` a partial `logging.proto.Event`
// into `data_->encoded_remaining`. // containing the specified string data using a `Value` field appropriate to
LogMessage& LogMessage::LogString(bool literal, absl::string_view str) { // `str_type`. Truncates `str` if necessary, but emits nothing and marks the
// Don't commit the MessageStart if the String tag_type and length don't fit. // buffer full if even the field headers do not fit.
void LogMessage::CopyToEncodedBuffer(absl::string_view str,
StringType str_type) {
auto encoded_remaining_copy = data_->encoded_remaining; auto encoded_remaining_copy = data_->encoded_remaining;
auto start = EncodeMessageStart( auto start = EncodeMessageStart(
EventTag::kValue, BufferSizeFor(WireType::kLengthDelimited) + str.size(), EventTag::kValue, BufferSizeFor(WireType::kLengthDelimited) + str.size(),
&encoded_remaining_copy); &encoded_remaining_copy);
if (EncodeStringTruncate( // If the `logging.proto.Event.value` field header did not fit,
literal ? ValueTag::kStringLiteral : ValueTag::kString, str, // `EncodeMessageStart` will have zeroed `encoded_remaining_copy`'s size and
&encoded_remaining_copy)) { // `EncodeStringTruncate` will fail too.
if (EncodeStringTruncate(str_type == StringType::kLiteral
? ValueTag::kStringLiteral
: ValueTag::kString,
str, &encoded_remaining_copy)) {
// The string may have been truncated, but the field header fit.
EncodeMessageLength(start, &encoded_remaining_copy); 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
// write anything else later.
data_->encoded_remaining.remove_suffix(data_->encoded_remaining.size());
} }
return *this;
} }
LogMessageFatal::LogMessageFatal(const char* file, int line) LogMessageFatal::LogMessageFatal(const char* file, int line)
......
...@@ -216,6 +216,13 @@ class LogMessage { ...@@ -216,6 +216,13 @@ class LogMessage {
absl::Span<char> string_start_; absl::Span<char> string_start_;
}; };
enum class StringType {
kLiteral,
kNotLiteral,
};
void CopyToEncodedBuffer(absl::string_view str,
StringType str_type) ABSL_ATTRIBUTE_NOINLINE;
// Returns `true` if the message is fatal or enabled debug-fatal. // Returns `true` if the message is fatal or enabled debug-fatal.
bool IsFatal() const; bool IsFatal() const;
...@@ -228,9 +235,6 @@ class LogMessage { ...@@ -228,9 +235,6 @@ class LogMessage {
// Checks `FLAGS_log_backtrace_at` and appends a backtrace if appropriate. // Checks `FLAGS_log_backtrace_at` and appends a backtrace if appropriate.
void LogBacktraceIfNeeded(); void LogBacktraceIfNeeded();
LogMessage& LogString(bool literal,
absl::string_view str) ABSL_ATTRIBUTE_NOINLINE;
// This should be the first data member so that its initializer captures errno // This should be the first data member so that its initializer captures errno
// before any other initializers alter it (e.g. with calls to new) and so that // before any other initializers alter it (e.g. with calls to new) and so that
// no other destructors run afterward an alter it (e.g. with calls to delete). // no other destructors run afterward an alter it (e.g. with calls to delete).
...@@ -282,15 +286,15 @@ LogMessage& LogMessage::operator<<(const T& v) { ...@@ -282,15 +286,15 @@ LogMessage& LogMessage::operator<<(const T& v) {
template <int SIZE> template <int SIZE>
LogMessage& LogMessage::operator<<(const char (&buf)[SIZE]) { LogMessage& LogMessage::operator<<(const char (&buf)[SIZE]) {
const bool literal = true; CopyToEncodedBuffer(buf, StringType::kLiteral);
return LogString(literal, buf); return *this;
} }
// Note: the following is declared `ABSL_ATTRIBUTE_NOINLINE` // Note: the following is declared `ABSL_ATTRIBUTE_NOINLINE`
template <int SIZE> template <int SIZE>
LogMessage& LogMessage::operator<<(char (&buf)[SIZE]) { LogMessage& LogMessage::operator<<(char (&buf)[SIZE]) {
const bool literal = false; CopyToEncodedBuffer(buf, StringType::kNotLiteral);
return LogString(literal, buf); return *this;
} }
// We instantiate these specializations in the library's TU to save space in // We instantiate these specializations in the library's TU to save space in
// other TUs. Since the template is marked `ABSL_ATTRIBUTE_NOINLINE` we will be // other TUs. Since the template is marked `ABSL_ATTRIBUTE_NOINLINE` we will be
......
...@@ -106,7 +106,8 @@ bool EncodeBytesTruncate(uint64_t tag, absl::Span<const char> value, ...@@ -106,7 +106,8 @@ bool EncodeBytesTruncate(uint64_t tag, absl::Span<const char> value,
const uint64_t tag_type = MakeTagType(tag, WireType::kLengthDelimited); const uint64_t tag_type = MakeTagType(tag, WireType::kLengthDelimited);
const uint64_t tag_type_size = VarintSize(tag_type); const uint64_t tag_type_size = VarintSize(tag_type);
uint64_t length = value.size(); uint64_t length = value.size();
const uint64_t length_size = VarintSize(length); const uint64_t length_size =
VarintSize(std::min<uint64_t>(length, buf->size()));
if (tag_type_size + length_size <= buf->size() && if (tag_type_size + length_size <= buf->size() &&
tag_type_size + length_size + value.size() > buf->size()) { tag_type_size + length_size + value.size() > buf->size()) {
value.remove_suffix(tag_type_size + length_size + value.size() - value.remove_suffix(tag_type_size + length_size + value.size() -
......
...@@ -41,12 +41,13 @@ class ABSL_MUST_USE_RESULT AsLiteralImpl final { ...@@ -41,12 +41,13 @@ class ABSL_MUST_USE_RESULT AsLiteralImpl final {
friend std::ostream& operator<<(std::ostream& os, AsLiteralImpl as_literal) { friend std::ostream& operator<<(std::ostream& os, AsLiteralImpl as_literal) {
return os << as_literal.str_; return os << as_literal.str_;
} }
log_internal::LogMessage& AddToMessage(log_internal::LogMessage& m) { void AddToMessage(log_internal::LogMessage& m) {
return m.LogString(/* literal = */ true, str_); m.CopyToEncodedBuffer(str_, log_internal::LogMessage::StringType::kLiteral);
} }
friend log_internal::LogMessage& operator<<(log_internal::LogMessage& m, friend log_internal::LogMessage& operator<<(log_internal::LogMessage& m,
AsLiteralImpl as_literal) { AsLiteralImpl as_literal) {
return as_literal.AddToMessage(m); as_literal.AddToMessage(m);
return m;
} }
}; };
......
...@@ -18,6 +18,7 @@ ...@@ -18,6 +18,7 @@
#include <cassert> #include <cassert>
#include <iostream> #include <iostream>
#include <string> #include <string>
#include <type_traits>
#include "absl/base/attributes.h" #include "absl/base/attributes.h"
#include "absl/base/config.h" #include "absl/base/config.h"
......
...@@ -15,6 +15,7 @@ ...@@ -15,6 +15,7 @@
#include "absl/log/internal/test_matchers.h" #include "absl/log/internal/test_matchers.h"
#include <ostream>
#include <sstream> #include <sstream>
#include <string> #include <string>
#include <type_traits> #include <type_traits>
...@@ -32,74 +33,138 @@ ...@@ -32,74 +33,138 @@
namespace absl { namespace absl {
ABSL_NAMESPACE_BEGIN ABSL_NAMESPACE_BEGIN
namespace log_internal { namespace log_internal {
namespace {
using ::testing::_;
using ::testing::AllOf;
using ::testing::Ge;
using ::testing::HasSubstr;
using ::testing::MakeMatcher;
using ::testing::Matcher;
using ::testing::MatcherInterface;
using ::testing::MatchResultListener;
using ::testing::Not;
using ::testing::Property;
using ::testing::ResultOf;
using ::testing::Truly;
class AsStringImpl final
: public MatcherInterface<absl::string_view> {
public:
explicit AsStringImpl(
const Matcher<const std::string&>& str_matcher)
: str_matcher_(str_matcher) {}
bool MatchAndExplain(
absl::string_view actual,
MatchResultListener* listener) const override {
return str_matcher_.MatchAndExplain(std::string(actual), listener);
}
void DescribeTo(std::ostream* os) const override {
return str_matcher_.DescribeTo(os);
}
void DescribeNegationTo(std::ostream* os) const override {
return str_matcher_.DescribeNegationTo(os);
}
private:
const Matcher<const std::string&> str_matcher_;
};
class MatchesOstreamImpl final
: public MatcherInterface<absl::string_view> {
public:
explicit MatchesOstreamImpl(std::string expected)
: expected_(std::move(expected)) {}
bool MatchAndExplain(absl::string_view actual,
MatchResultListener*) const override {
return actual == expected_;
}
void DescribeTo(std::ostream* os) const override {
*os << "matches the contents of the ostringstream, which are \""
<< expected_ << "\"";
}
void DescribeNegationTo(std::ostream* os) const override {
*os << "does not match the contents of the ostringstream, which are \""
<< expected_ << "\"";
}
::testing::Matcher<const absl::LogEntry&> SourceFilename( private:
const ::testing::Matcher<absl::string_view>& source_filename) { const std::string expected_;
};
} // namespace
Matcher<absl::string_view> AsString(
const Matcher<const std::string&>& str_matcher) {
return MakeMatcher(new AsStringImpl(str_matcher));
}
Matcher<const absl::LogEntry&> SourceFilename(
const Matcher<absl::string_view>& source_filename) {
return Property("source_filename", &absl::LogEntry::source_filename, return Property("source_filename", &absl::LogEntry::source_filename,
source_filename); source_filename);
} }
::testing::Matcher<const absl::LogEntry&> SourceBasename( Matcher<const absl::LogEntry&> SourceBasename(
const ::testing::Matcher<absl::string_view>& source_basename) { const Matcher<absl::string_view>& source_basename) {
return Property("source_basename", &absl::LogEntry::source_basename, return Property("source_basename", &absl::LogEntry::source_basename,
source_basename); source_basename);
} }
::testing::Matcher<const absl::LogEntry&> SourceLine( Matcher<const absl::LogEntry&> SourceLine(
const ::testing::Matcher<int>& source_line) { const Matcher<int>& source_line) {
return Property("source_line", &absl::LogEntry::source_line, source_line); return Property("source_line", &absl::LogEntry::source_line, source_line);
} }
::testing::Matcher<const absl::LogEntry&> Prefix( Matcher<const absl::LogEntry&> Prefix(
const ::testing::Matcher<bool>& prefix) { const Matcher<bool>& prefix) {
return Property("prefix", &absl::LogEntry::prefix, prefix); return Property("prefix", &absl::LogEntry::prefix, prefix);
} }
::testing::Matcher<const absl::LogEntry&> LogSeverity( Matcher<const absl::LogEntry&> LogSeverity(
const ::testing::Matcher<absl::LogSeverity>& log_severity) { const Matcher<absl::LogSeverity>& log_severity) {
return Property("log_severity", &absl::LogEntry::log_severity, log_severity); return Property("log_severity", &absl::LogEntry::log_severity, log_severity);
} }
::testing::Matcher<const absl::LogEntry&> Timestamp( Matcher<const absl::LogEntry&> Timestamp(
const ::testing::Matcher<absl::Time>& timestamp) { const Matcher<absl::Time>& timestamp) {
return Property("timestamp", &absl::LogEntry::timestamp, timestamp); return Property("timestamp", &absl::LogEntry::timestamp, timestamp);
} }
::testing::Matcher<const absl::LogEntry&> TimestampInMatchWindow() { Matcher<const absl::LogEntry&> TimestampInMatchWindow() {
return Property("timestamp", &absl::LogEntry::timestamp, return Property("timestamp", &absl::LogEntry::timestamp,
::testing::AllOf(::testing::Ge(absl::Now()), AllOf(Ge(absl::Now()), Truly([](absl::Time arg) {
::testing::Truly([](absl::Time arg) { return arg <= absl::Now();
return arg <= absl::Now(); })));
})));
} }
::testing::Matcher<const absl::LogEntry&> ThreadID( Matcher<const absl::LogEntry&> ThreadID(
const ::testing::Matcher<absl::LogEntry::tid_t>& tid) { const Matcher<absl::LogEntry::tid_t>& tid) {
return Property("tid", &absl::LogEntry::tid, tid); return Property("tid", &absl::LogEntry::tid, tid);
} }
::testing::Matcher<const absl::LogEntry&> TextMessageWithPrefixAndNewline( Matcher<const absl::LogEntry&> TextMessageWithPrefixAndNewline(
const ::testing::Matcher<absl::string_view>& const Matcher<absl::string_view>&
text_message_with_prefix_and_newline) { text_message_with_prefix_and_newline) {
return Property("text_message_with_prefix_and_newline", return Property("text_message_with_prefix_and_newline",
&absl::LogEntry::text_message_with_prefix_and_newline, &absl::LogEntry::text_message_with_prefix_and_newline,
text_message_with_prefix_and_newline); text_message_with_prefix_and_newline);
} }
::testing::Matcher<const absl::LogEntry&> TextMessageWithPrefix( Matcher<const absl::LogEntry&> TextMessageWithPrefix(
const ::testing::Matcher<absl::string_view>& text_message_with_prefix) { const Matcher<absl::string_view>& text_message_with_prefix) {
return Property("text_message_with_prefix", return Property("text_message_with_prefix",
&absl::LogEntry::text_message_with_prefix, &absl::LogEntry::text_message_with_prefix,
text_message_with_prefix); text_message_with_prefix);
} }
::testing::Matcher<const absl::LogEntry&> TextMessage( Matcher<const absl::LogEntry&> TextMessage(
const ::testing::Matcher<absl::string_view>& text_message) { const Matcher<absl::string_view>& text_message) {
return Property("text_message", &absl::LogEntry::text_message, text_message); return Property("text_message", &absl::LogEntry::text_message, text_message);
} }
::testing::Matcher<const absl::LogEntry&> TextPrefix( Matcher<const absl::LogEntry&> TextPrefix(
const ::testing::Matcher<absl::string_view>& text_prefix) { const Matcher<absl::string_view>& text_prefix) {
return ResultOf( return ResultOf(
[](const absl::LogEntry& entry) { [](const absl::LogEntry& entry) {
absl::string_view msg = entry.text_message_with_prefix(); absl::string_view msg = entry.text_message_with_prefix();
...@@ -108,42 +173,25 @@ namespace log_internal { ...@@ -108,42 +173,25 @@ namespace log_internal {
}, },
text_prefix); text_prefix);
} }
Matcher<const absl::LogEntry&> RawEncodedMessage(
const Matcher<absl::string_view>& raw_encoded_message) {
return Property("encoded_message", &absl::LogEntry::encoded_message,
raw_encoded_message);
}
::testing::Matcher<const absl::LogEntry&> Verbosity( Matcher<const absl::LogEntry&> Verbosity(
const ::testing::Matcher<int>& verbosity) { const Matcher<int>& verbosity) {
return Property("verbosity", &absl::LogEntry::verbosity, verbosity); return Property("verbosity", &absl::LogEntry::verbosity, verbosity);
} }
::testing::Matcher<const absl::LogEntry&> Stacktrace( Matcher<const absl::LogEntry&> Stacktrace(
const ::testing::Matcher<absl::string_view>& stacktrace) { const Matcher<absl::string_view>& stacktrace) {
return Property("stacktrace", &absl::LogEntry::stacktrace, stacktrace); return Property("stacktrace", &absl::LogEntry::stacktrace, stacktrace);
} }
class MatchesOstreamImpl final Matcher<absl::string_view> MatchesOstream(
: public ::testing::MatcherInterface<absl::string_view> {
public:
explicit MatchesOstreamImpl(std::string expected)
: expected_(std::move(expected)) {}
bool MatchAndExplain(absl::string_view actual,
::testing::MatchResultListener*) const override {
return actual == expected_;
}
void DescribeTo(std::ostream* os) const override {
*os << "matches the contents of the ostringstream, which are \""
<< expected_ << "\"";
}
void DescribeNegationTo(std::ostream* os) const override {
*os << "does not match the contents of the ostringstream, which are \""
<< expected_ << "\"";
}
private:
const std::string expected_;
};
::testing::Matcher<absl::string_view> MatchesOstream(
const std::ostringstream& stream) { const std::ostringstream& stream) {
return ::testing::MakeMatcher(new MatchesOstreamImpl(stream.str())); return MakeMatcher(new MatchesOstreamImpl(stream.str()));
} }
// We need to validate what is and isn't logged as the process dies due to // We need to validate what is and isn't logged as the process dies due to
...@@ -152,16 +200,16 @@ class MatchesOstreamImpl final ...@@ -152,16 +200,16 @@ class MatchesOstreamImpl final
// Instead, we use the mock actions `DeathTestExpectedLogging` and // Instead, we use the mock actions `DeathTestExpectedLogging` and
// `DeathTestUnexpectedLogging` to write specific phrases to `stderr` that we // `DeathTestUnexpectedLogging` to write specific phrases to `stderr` that we
// can validate in the parent process using this matcher. // can validate in the parent process using this matcher.
::testing::Matcher<const std::string&> DeathTestValidateExpectations() { Matcher<const std::string&> DeathTestValidateExpectations() {
if (log_internal::LoggingEnabledAt(absl::LogSeverity::kFatal)) { if (log_internal::LoggingEnabledAt(absl::LogSeverity::kFatal)) {
return ::testing::Matcher<const std::string&>(::testing::AllOf( return Matcher<const std::string&>(
::testing::HasSubstr("Mock received expected entry"), AllOf(HasSubstr("Mock received expected entry"),
Not(::testing::HasSubstr("Mock received unexpected entry")))); Not(HasSubstr("Mock received unexpected entry"))));
} }
// If `FATAL` logging is disabled, neither message should have been written. // If `FATAL` logging is disabled, neither message should have been written.
return ::testing::Matcher<const std::string&>(::testing::AllOf( return Matcher<const std::string&>(
Not(::testing::HasSubstr("Mock received expected entry")), AllOf(Not(HasSubstr("Mock received expected entry")),
Not(::testing::HasSubstr("Mock received unexpected entry")))); Not(HasSubstr("Mock received unexpected entry"))));
} }
} // namespace log_internal } // namespace log_internal
......
...@@ -38,6 +38,10 @@ ...@@ -38,6 +38,10 @@
namespace absl { namespace absl {
ABSL_NAMESPACE_BEGIN ABSL_NAMESPACE_BEGIN
namespace log_internal { namespace log_internal {
// In some configurations, Googletest's string matchers (e.g.
// `::testing::EndsWith`) need help to match `absl::string_view`.
::testing::Matcher<absl::string_view> AsString(
const ::testing::Matcher<const std::string&>& str_matcher);
// These matchers correspond to the components of `absl::LogEntry`. // These matchers correspond to the components of `absl::LogEntry`.
::testing::Matcher<const absl::LogEntry&> SourceFilename( ::testing::Matcher<const absl::LogEntry&> SourceFilename(
...@@ -79,6 +83,8 @@ namespace log_internal { ...@@ -79,6 +83,8 @@ namespace log_internal {
const std::ostringstream& stream); const std::ostringstream& stream);
::testing::Matcher<const std::string&> DeathTestValidateExpectations(); ::testing::Matcher<const std::string&> DeathTestValidateExpectations();
::testing::Matcher<const absl::LogEntry&> RawEncodedMessage(
const ::testing::Matcher<absl::string_view>& raw_encoded_message);
#define ENCODED_MESSAGE(message_matcher) ::testing::_ #define ENCODED_MESSAGE(message_matcher) ::testing::_
} // namespace log_internal } // namespace log_internal
......
...@@ -28,6 +28,7 @@ ...@@ -28,6 +28,7 @@
#endif #endif
#include "gmock/gmock.h" #include "gmock/gmock.h"
#include "gtest/gtest.h" #include "gtest/gtest.h"
#include "absl/log/check.h"
#include "absl/log/internal/test_matchers.h" #include "absl/log/internal/test_matchers.h"
#include "absl/log/log.h" #include "absl/log/log.h"
#include "absl/log/scoped_mock_log.h" #include "absl/log/scoped_mock_log.h"
...@@ -37,21 +38,20 @@ ...@@ -37,21 +38,20 @@
#include "absl/strings/string_view.h" #include "absl/strings/string_view.h"
namespace { namespace {
using ::absl::log_internal::AsString;
using ::absl::log_internal::MatchesOstream; using ::absl::log_internal::MatchesOstream;
using ::absl::log_internal::RawEncodedMessage;
using ::absl::log_internal::TextMessage; using ::absl::log_internal::TextMessage;
using ::absl::log_internal::TextPrefix; using ::absl::log_internal::TextPrefix;
using ::testing::AllOf; using ::testing::AllOf;
using ::testing::AnyOf; using ::testing::AnyOf;
using ::testing::Each; using ::testing::Each;
using ::testing::ElementsAre; using ::testing::EndsWith;
using ::testing::Eq; using ::testing::Eq;
using ::testing::Ge; using ::testing::Ge;
using ::testing::IsEmpty; using ::testing::IsEmpty;
using ::testing::Le; using ::testing::Le;
using ::testing::ResultOf;
using ::testing::SizeIs; using ::testing::SizeIs;
using ::testing::Truly;
using ::testing::Types; using ::testing::Types;
// Some aspects of formatting streamed data (e.g. pointer handling) are // Some aspects of formatting streamed data (e.g. pointer handling) are
...@@ -72,15 +72,12 @@ TEST(LogFormatTest, NoMessage) { ...@@ -72,15 +72,12 @@ TEST(LogFormatTest, NoMessage) {
const int log_line = __LINE__ + 1; const int log_line = __LINE__ + 1;
auto do_log = [] { LOG(INFO); }; auto do_log = [] { LOG(INFO); };
EXPECT_CALL( EXPECT_CALL(test_sink,
test_sink, Send(AllOf(TextMessage(MatchesOstream(ComparisonStream())),
Send(AllOf( TextPrefix(AsString(EndsWith(absl::StrCat(
TextMessage(MatchesOstream(ComparisonStream())), " log_format_test.cc:", log_line, "] ")))),
TextPrefix(Truly([=](absl::string_view msg) { TextMessage(IsEmpty()),
return absl::EndsWith( ENCODED_MESSAGE(EqualsProto(R"pb()pb")))));
msg, absl::StrCat(" log_format_test.cc:", log_line, "] "));
})),
TextMessage(IsEmpty()), ENCODED_MESSAGE(EqualsProto(R"pb()pb")))));
test_sink.StartCapturingLogs(); test_sink.StartCapturingLogs();
do_log(); do_log();
...@@ -1660,19 +1657,210 @@ TEST(StructuredLoggingOverflowTest, TruncatesStrings) { ...@@ -1660,19 +1657,210 @@ TEST(StructuredLoggingOverflowTest, TruncatesStrings) {
SizeIs(AllOf(Ge(absl::log_internal::kLogMessageBufferSize - 256), SizeIs(AllOf(Ge(absl::log_internal::kLogMessageBufferSize - 256),
Le(absl::log_internal::kLogMessageBufferSize))), Le(absl::log_internal::kLogMessageBufferSize))),
Each(Eq('x')))), Each(Eq('x')))),
ENCODED_MESSAGE(ResultOf( ENCODED_MESSAGE(HasOneStrThat(AllOf(
[](const logging::proto::Event& e) { return e.value(); }, SizeIs(AllOf(Ge(absl::log_internal::kLogMessageBufferSize - 256),
ElementsAre(ResultOf( Le(absl::log_internal::kLogMessageBufferSize))),
[](const logging::proto::Value& v) { Each(Eq('x'))))))));
return std::string(v.str());
},
AllOf(SizeIs(AllOf(
Ge(absl::log_internal::kLogMessageBufferSize - 256),
Le(absl::log_internal::kLogMessageBufferSize))),
Each(Eq('x'))))))))));
test_sink.StartCapturingLogs(); test_sink.StartCapturingLogs();
LOG(INFO) << std::string(2 * absl::log_internal::kLogMessageBufferSize, 'x'); LOG(INFO) << std::string(2 * absl::log_internal::kLogMessageBufferSize, 'x');
} }
struct StringLike {
absl::string_view data;
};
std::ostream& operator<<(std::ostream& os, StringLike str) {
return os << str.data;
}
TEST(StructuredLoggingOverflowTest, TruncatesInsertionOperators) {
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
// This message is too long and should be truncated to some unspecified size
// no greater than the buffer size but not too much less either. It should be
// truncated rather than discarded.
EXPECT_CALL(
test_sink,
Send(AllOf(
TextMessage(AllOf(
SizeIs(AllOf(Ge(absl::log_internal::kLogMessageBufferSize - 256),
Le(absl::log_internal::kLogMessageBufferSize))),
Each(Eq('x')))),
ENCODED_MESSAGE(HasOneStrThat(AllOf(
SizeIs(AllOf(Ge(absl::log_internal::kLogMessageBufferSize - 256),
Le(absl::log_internal::kLogMessageBufferSize))),
Each(Eq('x'))))))));
test_sink.StartCapturingLogs();
LOG(INFO) << StringLike{
std::string(2 * absl::log_internal::kLogMessageBufferSize, 'x')};
}
// Returns the size of the largest string that will fit in a `LOG` message
// buffer with no prefix.
size_t MaxLogFieldLengthNoPrefix() {
class StringLengthExtractorSink : public absl::LogSink {
public:
void Send(const absl::LogEntry& entry) override {
CHECK_EQ(size_, -1);
CHECK_EQ(entry.text_message().find_first_not_of('x'),
absl::string_view::npos);
size_ = entry.text_message().size();
}
size_t size() const {
CHECK_GT(size_, 0);
return size_;
}
private:
size_t size_ = -1;
} extractor_sink;
LOG(INFO).NoPrefix().ToSinkOnly(&extractor_sink)
<< std::string(2 * absl::log_internal::kLogMessageBufferSize, 'x');
return extractor_sink.size();
}
TEST(StructuredLoggingOverflowTest, TruncatesStringsCleanly) {
const size_t longest_fit = MaxLogFieldLengthNoPrefix();
// To log a second value field, we need four bytes: two tag/type bytes and two
// sizes. To put any data in the field we need a fifth byte.
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits exactly, no part of y fits.
LOG(INFO).NoPrefix() << std::string(longest_fit, 'x') << "y";
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit - 1), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits, one byte from y's header fits but shouldn't be visible.
LOG(INFO).NoPrefix() << std::string(longest_fit - 1, 'x') << "y";
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit - 2), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits, two bytes from y's header fit but shouldn't be visible.
LOG(INFO).NoPrefix() << std::string(longest_fit - 2, 'x') << "y";
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit - 3), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits, three bytes from y's header fit but shouldn't be visible.
LOG(INFO).NoPrefix() << std::string(longest_fit - 3, 'x') << "y";
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrAndOneLiteralThat(
AllOf(SizeIs(longest_fit - 4), Each(Eq('x'))),
IsEmpty())),
RawEncodedMessage(Not(AsString(EndsWith("x")))))));
test_sink.StartCapturingLogs();
// x fits, all four bytes from y's header fit but no data bytes do, so we
// encode an empty string.
LOG(INFO).NoPrefix() << std::string(longest_fit - 4, 'x') << "y";
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(
test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrAndOneLiteralThat(
AllOf(SizeIs(longest_fit - 5), Each(Eq('x'))), Eq("y"))),
RawEncodedMessage(AsString(EndsWith("y"))))));
test_sink.StartCapturingLogs();
// x fits, y fits exactly.
LOG(INFO).NoPrefix() << std::string(longest_fit - 5, 'x') << "y";
}
}
TEST(StructuredLoggingOverflowTest, TruncatesInsertionOperatorsCleanly) {
const size_t longest_fit = MaxLogFieldLengthNoPrefix();
// To log a second value field, we need four bytes: two tag/type bytes and two
// sizes. To put any data in the field we need a fifth byte.
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits exactly, no part of y fits.
LOG(INFO).NoPrefix() << std::string(longest_fit, 'x') << StringLike{"y"};
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit - 1), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits, one byte from y's header fits but shouldn't be visible.
LOG(INFO).NoPrefix() << std::string(longest_fit - 1, 'x')
<< StringLike{"y"};
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit - 2), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits, two bytes from y's header fit but shouldn't be visible.
LOG(INFO).NoPrefix() << std::string(longest_fit - 2, 'x')
<< StringLike{"y"};
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit - 3), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits, three bytes from y's header fit but shouldn't be visible.
LOG(INFO).NoPrefix() << std::string(longest_fit - 3, 'x')
<< StringLike{"y"};
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(test_sink,
Send(AllOf(ENCODED_MESSAGE(HasOneStrThat(
AllOf(SizeIs(longest_fit - 4), Each(Eq('x'))))),
RawEncodedMessage(AsString(EndsWith("x"))))));
test_sink.StartCapturingLogs();
// x fits, all four bytes from y's header fit but no data bytes do. We
// don't encode an empty string here because every I/O manipulator hits this
// codepath and those shouldn't leave empty strings behind.
LOG(INFO).NoPrefix() << std::string(longest_fit - 4, 'x')
<< StringLike{"y"};
}
{
absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
EXPECT_CALL(
test_sink,
Send(AllOf(ENCODED_MESSAGE(HasTwoStrsThat(
AllOf(SizeIs(longest_fit - 5), Each(Eq('x'))), Eq("y"))),
RawEncodedMessage(AsString(EndsWith("y"))))));
test_sink.StartCapturingLogs();
// x fits, y fits exactly.
LOG(INFO).NoPrefix() << std::string(longest_fit - 5, 'x')
<< StringLike{"y"};
}
}
} // namespace } // namespace
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment