summaryrefslogtreecommitdiff
path: root/absl/log
diff options
context:
space:
mode:
authorGravatar Andy Getzendanner <durandal@google.com>2022-11-21 21:17:53 -0800
committerGravatar Copybara-Service <copybara-worker@google.com>2022-11-21 21:18:39 -0800
commit9a7e8e36300c6d89c7f9a2539f7aabf8e0031106 (patch)
treecbf03dd0ec10bc81451b996df4c9e8437d702ca1 /absl/log
parentd081b629b7c201e701911cfb4e0c99735c21c331 (diff)
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
Diffstat (limited to 'absl/log')
-rw-r--r--absl/log/BUILD.bazel1
-rw-r--r--absl/log/CMakeLists.txt1
-rw-r--r--absl/log/internal/log_message.cc57
-rw-r--r--absl/log/internal/log_message.h18
-rw-r--r--absl/log/internal/proto.cc3
-rw-r--r--absl/log/internal/structured.h7
-rw-r--r--absl/log/internal/test_actions.cc1
-rw-r--r--absl/log/internal/test_matchers.cc172
-rw-r--r--absl/log/internal/test_matchers.h6
-rw-r--r--absl/log/log_format_test.cc234
10 files changed, 382 insertions, 118 deletions
diff --git a/absl/log/BUILD.bazel b/absl/log/BUILD.bazel
index 733b0c3f..b5ce616c 100644
--- a/absl/log/BUILD.bazel
+++ b/absl/log/BUILD.bazel
@@ -332,6 +332,7 @@ cc_test(
copts = ABSL_TEST_COPTS,
linkopts = ABSL_DEFAULT_LINKOPTS,
deps = [
+ ":check",
":log",
":scoped_mock_log",
"//absl/log/internal:test_matchers",
diff --git a/absl/log/CMakeLists.txt b/absl/log/CMakeLists.txt
index 2337d0c0..2ab08d81 100644
--- a/absl/log/CMakeLists.txt
+++ b/absl/log/CMakeLists.txt
@@ -745,6 +745,7 @@ absl_cc_test(
LINKOPTS
${ABSL_DEFAULT_LINKOPTS}
DEPS
+ absl::check
absl::log
absl::log_internal_test_matchers
absl::scoped_mock_log
diff --git a/absl/log/internal/log_message.cc b/absl/log/internal/log_message.cc
index b7313551..6b4804f1 100644
--- a/absl/log/internal/log_message.cc
+++ b/absl/log/internal/log_message.cc
@@ -345,11 +345,13 @@ void LogMessage::FailQuietly() {
}
LogMessage& LogMessage::operator<<(const std::string& v) {
- return LogString(false, v);
+ CopyToEncodedBuffer(v, StringType::kNotLiteral);
+ return *this;
}
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)) {
OstreamView view(*data_);
@@ -424,27 +426,28 @@ LogMessage::OstreamView::OstreamView(LogMessageData& message_data)
&encoded_remaining_copy_);
string_start_ =
EncodeMessageStart(ValueTag::kString, encoded_remaining_copy_.size(),
- &encoded_remaining_copy_);
+ &encoded_remaining_copy_);
setp(encoded_remaining_copy_.data(),
encoded_remaining_copy_.data() + encoded_remaining_copy_.size());
data_.manipulated.rdbuf(this);
}
LogMessage::OstreamView::~OstreamView() {
- const absl::Span<const char> contents(pbase(),
- static_cast<size_t>(pptr() - pbase()));
- encoded_remaining_copy_.remove_prefix(contents.size());
+ data_.manipulated.rdbuf(nullptr);
if (!string_start_.data()) {
- // The headers didn't fit; we won't write anything to the buffer, but we
- // also need to zero the size of `data_->encoded_remaining` so that no more
- // data is encoded.
+ // 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());
- } else if (!contents.empty()) {
- EncodeMessageLength(string_start_, &encoded_remaining_copy_);
- EncodeMessageLength(message_start_, &encoded_remaining_copy_);
- data_.encoded_remaining = encoded_remaining_copy_;
+ return;
}
- 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; }
@@ -511,21 +514,31 @@ void LogMessage::LogBacktraceIfNeeded() {
view.stream() << ") ";
}
-// Encodes a partial `logging.proto.Event` containing the specified string data
-// into `data_->encoded_remaining`.
-LogMessage& LogMessage::LogString(bool literal, absl::string_view str) {
- // Don't commit the MessageStart if the String tag_type and length don't fit.
+// 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.
+void LogMessage::CopyToEncodedBuffer(absl::string_view str,
+ StringType str_type) {
auto encoded_remaining_copy = data_->encoded_remaining;
auto start = EncodeMessageStart(
EventTag::kValue, BufferSizeFor(WireType::kLengthDelimited) + str.size(),
&encoded_remaining_copy);
- if (EncodeStringTruncate(
- literal ? ValueTag::kStringLiteral : ValueTag::kString, str,
- &encoded_remaining_copy)) {
+ // If the `logging.proto.Event.value` field header did not fit,
+ // `EncodeMessageStart` will have zeroed `encoded_remaining_copy`'s size and
+ // `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);
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)
diff --git a/absl/log/internal/log_message.h b/absl/log/internal/log_message.h
index 5914a535..7302dde0 100644
--- a/absl/log/internal/log_message.h
+++ b/absl/log/internal/log_message.h
@@ -216,6 +216,13 @@ class LogMessage {
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.
bool IsFatal() const;
@@ -228,9 +235,6 @@ class LogMessage {
// Checks `FLAGS_log_backtrace_at` and appends a backtrace if appropriate.
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
// 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).
@@ -282,15 +286,15 @@ LogMessage& LogMessage::operator<<(const T& v) {
template <int SIZE>
LogMessage& LogMessage::operator<<(const char (&buf)[SIZE]) {
- const bool literal = true;
- return LogString(literal, buf);
+ CopyToEncodedBuffer(buf, StringType::kLiteral);
+ return *this;
}
// Note: the following is declared `ABSL_ATTRIBUTE_NOINLINE`
template <int SIZE>
LogMessage& LogMessage::operator<<(char (&buf)[SIZE]) {
- const bool literal = false;
- return LogString(literal, buf);
+ CopyToEncodedBuffer(buf, StringType::kNotLiteral);
+ return *this;
}
// 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
diff --git a/absl/log/internal/proto.cc b/absl/log/internal/proto.cc
index 80d78eed..86c459b0 100644
--- a/absl/log/internal/proto.cc
+++ b/absl/log/internal/proto.cc
@@ -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_size = VarintSize(tag_type);
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() &&
tag_type_size + length_size + value.size() > buf->size()) {
value.remove_suffix(tag_type_size + length_size + value.size() -
diff --git a/absl/log/internal/structured.h b/absl/log/internal/structured.h
index 8888e7d7..08caea66 100644
--- a/absl/log/internal/structured.h
+++ b/absl/log/internal/structured.h
@@ -41,12 +41,13 @@ class ABSL_MUST_USE_RESULT AsLiteralImpl final {
friend std::ostream& operator<<(std::ostream& os, AsLiteralImpl as_literal) {
return os << as_literal.str_;
}
- log_internal::LogMessage& AddToMessage(log_internal::LogMessage& m) {
- return m.LogString(/* literal = */ true, str_);
+ void AddToMessage(log_internal::LogMessage& m) {
+ m.CopyToEncodedBuffer(str_, log_internal::LogMessage::StringType::kLiteral);
}
friend log_internal::LogMessage& operator<<(log_internal::LogMessage& m,
AsLiteralImpl as_literal) {
- return as_literal.AddToMessage(m);
+ as_literal.AddToMessage(m);
+ return m;
}
};
diff --git a/absl/log/internal/test_actions.cc b/absl/log/internal/test_actions.cc
index bb4af17f..bdfd6377 100644
--- a/absl/log/internal/test_actions.cc
+++ b/absl/log/internal/test_actions.cc
@@ -18,6 +18,7 @@
#include <cassert>
#include <iostream>
#include <string>
+#include <type_traits>
#include "absl/base/attributes.h"
#include "absl/base/config.h"
diff --git a/absl/log/internal/test_matchers.cc b/absl/log/internal/test_matchers.cc
index 72ca704e..8c6515c4 100644
--- a/absl/log/internal/test_matchers.cc
+++ b/absl/log/internal/test_matchers.cc
@@ -15,6 +15,7 @@
#include "absl/log/internal/test_matchers.h"
+#include <ostream>
#include <sstream>
#include <string>
#include <type_traits>
@@ -32,74 +33,138 @@
namespace absl {
ABSL_NAMESPACE_BEGIN
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(
- const ::testing::Matcher<absl::string_view>& source_filename) {
+ private:
+ 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,
source_filename);
}
-::testing::Matcher<const absl::LogEntry&> SourceBasename(
- const ::testing::Matcher<absl::string_view>& source_basename) {
+Matcher<const absl::LogEntry&> SourceBasename(
+ const Matcher<absl::string_view>& source_basename) {
return Property("source_basename", &absl::LogEntry::source_basename,
source_basename);
}
-::testing::Matcher<const absl::LogEntry&> SourceLine(
- const ::testing::Matcher<int>& source_line) {
+Matcher<const absl::LogEntry&> SourceLine(
+ const Matcher<int>& source_line) {
return Property("source_line", &absl::LogEntry::source_line, source_line);
}
-::testing::Matcher<const absl::LogEntry&> Prefix(
- const ::testing::Matcher<bool>& prefix) {
+Matcher<const absl::LogEntry&> Prefix(
+ const Matcher<bool>& prefix) {
return Property("prefix", &absl::LogEntry::prefix, prefix);
}
-::testing::Matcher<const absl::LogEntry&> LogSeverity(
- const ::testing::Matcher<absl::LogSeverity>& log_severity) {
+Matcher<const absl::LogEntry&> LogSeverity(
+ const Matcher<absl::LogSeverity>& log_severity) {
return Property("log_severity", &absl::LogEntry::log_severity, log_severity);
}
-::testing::Matcher<const absl::LogEntry&> Timestamp(
- const ::testing::Matcher<absl::Time>& timestamp) {
+Matcher<const absl::LogEntry&> Timestamp(
+ const Matcher<absl::Time>& 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,
- ::testing::AllOf(::testing::Ge(absl::Now()),
- ::testing::Truly([](absl::Time arg) {
- return arg <= absl::Now();
- })));
+ AllOf(Ge(absl::Now()), Truly([](absl::Time arg) {
+ return arg <= absl::Now();
+ })));
}
-::testing::Matcher<const absl::LogEntry&> ThreadID(
- const ::testing::Matcher<absl::LogEntry::tid_t>& tid) {
+Matcher<const absl::LogEntry&> ThreadID(
+ const Matcher<absl::LogEntry::tid_t>& tid) {
return Property("tid", &absl::LogEntry::tid, tid);
}
-::testing::Matcher<const absl::LogEntry&> TextMessageWithPrefixAndNewline(
- const ::testing::Matcher<absl::string_view>&
+Matcher<const absl::LogEntry&> TextMessageWithPrefixAndNewline(
+ const Matcher<absl::string_view>&
text_message_with_prefix_and_newline) {
return Property("text_message_with_prefix_and_newline",
&absl::LogEntry::text_message_with_prefix_and_newline,
text_message_with_prefix_and_newline);
}
-::testing::Matcher<const absl::LogEntry&> TextMessageWithPrefix(
- const ::testing::Matcher<absl::string_view>& text_message_with_prefix) {
+Matcher<const absl::LogEntry&> TextMessageWithPrefix(
+ const Matcher<absl::string_view>& text_message_with_prefix) {
return Property("text_message_with_prefix",
&absl::LogEntry::text_message_with_prefix,
text_message_with_prefix);
}
-::testing::Matcher<const absl::LogEntry&> TextMessage(
- const ::testing::Matcher<absl::string_view>& text_message) {
+Matcher<const absl::LogEntry&> TextMessage(
+ const Matcher<absl::string_view>& text_message) {
return Property("text_message", &absl::LogEntry::text_message, text_message);
}
-::testing::Matcher<const absl::LogEntry&> TextPrefix(
- const ::testing::Matcher<absl::string_view>& text_prefix) {
+Matcher<const absl::LogEntry&> TextPrefix(
+ const Matcher<absl::string_view>& text_prefix) {
return ResultOf(
[](const absl::LogEntry& entry) {
absl::string_view msg = entry.text_message_with_prefix();
@@ -108,42 +173,25 @@ namespace log_internal {
},
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(
- const ::testing::Matcher<int>& verbosity) {
+Matcher<const absl::LogEntry&> Verbosity(
+ const Matcher<int>& verbosity) {
return Property("verbosity", &absl::LogEntry::verbosity, verbosity);
}
-::testing::Matcher<const absl::LogEntry&> Stacktrace(
- const ::testing::Matcher<absl::string_view>& stacktrace) {
+Matcher<const absl::LogEntry&> Stacktrace(
+ const Matcher<absl::string_view>& stacktrace) {
return Property("stacktrace", &absl::LogEntry::stacktrace, stacktrace);
}
-class MatchesOstreamImpl final
- : 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(
+Matcher<absl::string_view> MatchesOstream(
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
@@ -152,16 +200,16 @@ class MatchesOstreamImpl final
// Instead, we use the mock actions `DeathTestExpectedLogging` and
// `DeathTestUnexpectedLogging` to write specific phrases to `stderr` that we
// 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)) {
- return ::testing::Matcher<const std::string&>(::testing::AllOf(
- ::testing::HasSubstr("Mock received expected entry"),
- Not(::testing::HasSubstr("Mock received unexpected entry"))));
+ return Matcher<const std::string&>(
+ AllOf(HasSubstr("Mock received expected entry"),
+ Not(HasSubstr("Mock received unexpected entry"))));
}
// If `FATAL` logging is disabled, neither message should have been written.
- return ::testing::Matcher<const std::string&>(::testing::AllOf(
- Not(::testing::HasSubstr("Mock received expected entry")),
- Not(::testing::HasSubstr("Mock received unexpected entry"))));
+ return Matcher<const std::string&>(
+ AllOf(Not(HasSubstr("Mock received expected entry")),
+ Not(HasSubstr("Mock received unexpected entry"))));
}
} // namespace log_internal
diff --git a/absl/log/internal/test_matchers.h b/absl/log/internal/test_matchers.h
index c18cb6e9..fc653a91 100644
--- a/absl/log/internal/test_matchers.h
+++ b/absl/log/internal/test_matchers.h
@@ -38,6 +38,10 @@
namespace absl {
ABSL_NAMESPACE_BEGIN
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`.
::testing::Matcher<const absl::LogEntry&> SourceFilename(
@@ -79,6 +83,8 @@ namespace log_internal {
const std::ostringstream& stream);
::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::_
} // namespace log_internal
diff --git a/absl/log/log_format_test.cc b/absl/log/log_format_test.cc
index cf087ca8..5ff6f159 100644
--- a/absl/log/log_format_test.cc
+++ b/absl/log/log_format_test.cc
@@ -28,6 +28,7 @@
#endif
#include "gmock/gmock.h"
#include "gtest/gtest.h"
+#include "absl/log/check.h"
#include "absl/log/internal/test_matchers.h"
#include "absl/log/log.h"
#include "absl/log/scoped_mock_log.h"
@@ -37,21 +38,20 @@
#include "absl/strings/string_view.h"
namespace {
+using ::absl::log_internal::AsString;
using ::absl::log_internal::MatchesOstream;
+using ::absl::log_internal::RawEncodedMessage;
using ::absl::log_internal::TextMessage;
using ::absl::log_internal::TextPrefix;
-
using ::testing::AllOf;
using ::testing::AnyOf;
using ::testing::Each;
-using ::testing::ElementsAre;
+using ::testing::EndsWith;
using ::testing::Eq;
using ::testing::Ge;
using ::testing::IsEmpty;
using ::testing::Le;
-using ::testing::ResultOf;
using ::testing::SizeIs;
-using ::testing::Truly;
using ::testing::Types;
// Some aspects of formatting streamed data (e.g. pointer handling) are
@@ -72,15 +72,12 @@ TEST(LogFormatTest, NoMessage) {
const int log_line = __LINE__ + 1;
auto do_log = [] { LOG(INFO); };
- EXPECT_CALL(
- test_sink,
- Send(AllOf(
- TextMessage(MatchesOstream(ComparisonStream())),
- TextPrefix(Truly([=](absl::string_view msg) {
- return absl::EndsWith(
- msg, absl::StrCat(" log_format_test.cc:", log_line, "] "));
- })),
- TextMessage(IsEmpty()), ENCODED_MESSAGE(EqualsProto(R"pb()pb")))));
+ EXPECT_CALL(test_sink,
+ Send(AllOf(TextMessage(MatchesOstream(ComparisonStream())),
+ TextPrefix(AsString(EndsWith(absl::StrCat(
+ " log_format_test.cc:", log_line, "] ")))),
+ TextMessage(IsEmpty()),
+ ENCODED_MESSAGE(EqualsProto(R"pb()pb")))));
test_sink.StartCapturingLogs();
do_log();
@@ -1660,19 +1657,210 @@ TEST(StructuredLoggingOverflowTest, TruncatesStrings) {
SizeIs(AllOf(Ge(absl::log_internal::kLogMessageBufferSize - 256),
Le(absl::log_internal::kLogMessageBufferSize))),
Each(Eq('x')))),
- ENCODED_MESSAGE(ResultOf(
- [](const logging::proto::Event& e) { return e.value(); },
- ElementsAre(ResultOf(
- [](const logging::proto::Value& v) {
- return std::string(v.str());
- },
- 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) << 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