Skip to content

A
abseil-cpp
Commit f82e3f35 by Andy Getzendanner Committed by Copybara-Service
Options

Refactor "RAW: " prefix formatting into FormatLogPrefix. 

This is used when demoting regular logging inside a LogSink::Send to raw-like to avoid infinite recursive dispatch.

PiperOrigin-RevId: 488934154
Change-Id: I0aaaeea0ceaaff3c4394308a7102a55befbef290
parent f02e8c04
Showing with 69 additions and 20 deletions
absl/log/internal/log_format.cc
...@@ -169,13 +169,13 @@ std::string FormatLogMessage(absl::LogSeverity severity, ...@@ -169,13 +169,13 @@ std::string FormatLogMessage(absl::LogSeverity severity,
absl::CivilSecond civil_second, absl::CivilSecond civil_second,
absl::Duration subsecond, log_internal::Tid tid, absl::Duration subsecond, log_internal::Tid tid,
absl::string_view basename, int line, absl::string_view basename, int line,
absl::string_view message) { PrefixFormat format, absl::string_view message) {
return absl::StrFormat( return absl::StrFormat(
"%c%02d%02d %02d:%02d:%02d.%06d %7d %s:%d] %s", "%c%02d%02d %02d:%02d:%02d.%06d %7d %s:%d] %s%s",
absl::LogSeverityName(severity)[0], civil_second.month(), absl::LogSeverityName(severity)[0], civil_second.month(),
civil_second.day(), civil_second.hour(), civil_second.minute(), civil_second.day(), civil_second.hour(), civil_second.minute(),
civil_second.second(), absl::ToInt64Microseconds(subsecond), tid, civil_second.second(), absl::ToInt64Microseconds(subsecond), tid,
basename, line, message); basename, line, format == PrefixFormat::kRaw ? "RAW: " : "", message);
} }
// This method is fairly hot, and the library always passes a huge `buf`, so we // This method is fairly hot, and the library always passes a huge `buf`, so we
...@@ -189,10 +189,12 @@ std::string FormatLogMessage(absl::LogSeverity severity, ...@@ -189,10 +189,12 @@ std::string FormatLogMessage(absl::LogSeverity severity,
// 3. line number and bracket // 3. line number and bracket
size_t FormatLogPrefix(absl::LogSeverity severity, absl::Time timestamp, size_t FormatLogPrefix(absl::LogSeverity severity, absl::Time timestamp,
log_internal::Tid tid, absl::string_view basename, log_internal::Tid tid, absl::string_view basename,
int line, absl::Span<char>& buf) { int line, PrefixFormat format, absl::Span<char>& buf) {
auto prefix_size = FormatBoundedFields(severity, timestamp, tid, buf); auto prefix_size = FormatBoundedFields(severity, timestamp, tid, buf);
prefix_size += log_internal::AppendTruncated(basename, buf); prefix_size += log_internal::AppendTruncated(basename, buf);
prefix_size += FormatLineNumber(line, buf); prefix_size += FormatLineNumber(line, buf);
if (format == PrefixFormat::kRaw)
prefix_size += log_internal::AppendTruncated("RAW: ", buf);
return prefix_size; return prefix_size;
} }
......
absl/log/internal/log_format.h
...@@ -38,12 +38,17 @@ namespace absl { ...@@ -38,12 +38,17 @@ namespace absl {
ABSL_NAMESPACE_BEGIN ABSL_NAMESPACE_BEGIN
namespace log_internal { namespace log_internal {
enum class PrefixFormat {
kNotRaw,
kRaw,
};
// Formats log message based on provided data. // Formats log message based on provided data.
std::string FormatLogMessage(absl::LogSeverity severity, std::string FormatLogMessage(absl::LogSeverity severity,
absl::CivilSecond civil_second, absl::CivilSecond civil_second,
absl::Duration subsecond, log_internal::Tid tid, absl::Duration subsecond, log_internal::Tid tid,
absl::string_view basename, int line, absl::string_view basename, int line,
absl::string_view message); PrefixFormat format, absl::string_view message);
// Formats various entry metadata into a text string meant for use as a // Formats various entry metadata into a text string meant for use as a
// prefix on a log message string. Writes into `buf`, advances `buf` to point // prefix on a log message string. Writes into `buf`, advances `buf` to point
...@@ -64,7 +69,7 @@ std::string FormatLogMessage(absl::LogSeverity severity, ...@@ -64,7 +69,7 @@ std::string FormatLogMessage(absl::LogSeverity severity,
// see a thread ID. // see a thread ID.
size_t FormatLogPrefix(absl::LogSeverity severity, absl::Time timestamp, size_t FormatLogPrefix(absl::LogSeverity severity, absl::Time timestamp,
log_internal::Tid tid, absl::string_view basename, log_internal::Tid tid, absl::string_view basename,
int line, absl::Span<char>& buf); int line, PrefixFormat format, absl::Span<char>& buf);
} // namespace log_internal } // namespace log_internal
ABSL_NAMESPACE_END ABSL_NAMESPACE_END
......
absl/log/internal/log_message.cc
...@@ -148,7 +148,10 @@ class LogEntryStreambuf final : public std::streambuf { ...@@ -148,7 +148,10 @@ class LogEntryStreambuf final : public std::streambuf {
absl::Span<char> remaining = buf_; absl::Span<char> remaining = buf_;
prefix_len_ = log_internal::FormatLogPrefix( prefix_len_ = log_internal::FormatLogPrefix(
entry_.log_severity(), entry_.timestamp(), entry_.tid(), entry_.log_severity(), entry_.timestamp(), entry_.tid(),
entry_.source_basename(), entry_.source_line(), remaining); entry_.source_basename(), entry_.source_line(),
log_internal::ThreadIsLoggingToLogSink() ? PrefixFormat::kRaw
: PrefixFormat::kNotRaw,
remaining);
pbump(static_cast<int>(prefix_len_)); pbump(static_cast<int>(prefix_len_));
} }
} }
......
absl/log/log_entry_test.cc
...@@ -59,8 +59,9 @@ class LogEntryTestPeer { ...@@ -59,8 +59,9 @@ class LogEntryTestPeer {
public: public:
LogEntryTestPeer(absl::string_view base_filename, int line, bool prefix, LogEntryTestPeer(absl::string_view base_filename, int line, bool prefix,
absl::LogSeverity severity, absl::string_view timestamp, absl::LogSeverity severity, absl::string_view timestamp,
absl::LogEntry::tid_t tid, absl::string_view text_message) absl::LogEntry::tid_t tid, PrefixFormat format,
: buf_(15000, '\0') { absl::string_view text_message)
: format_{format}, buf_(15000, '\0') {
entry_.base_filename_ = base_filename; entry_.base_filename_ = base_filename;
entry_.line_ = line; entry_.line_ = line;
entry_.prefix_ = prefix; entry_.prefix_ = prefix;
...@@ -88,7 +89,7 @@ class LogEntryTestPeer { ...@@ -88,7 +89,7 @@ class LogEntryTestPeer {
entry_.prefix_ entry_.prefix_
? log_internal::FormatLogPrefix( ? log_internal::FormatLogPrefix(
entry_.log_severity(), entry_.timestamp(), entry_.tid(), entry_.log_severity(), entry_.timestamp(), entry_.tid(),
entry_.source_basename(), entry_.source_line(), view) entry_.source_basename(), entry_.source_line(), format_, view)
: 0; : 0;
EXPECT_THAT(entry_.prefix_len_, EXPECT_THAT(entry_.prefix_len_,
...@@ -107,14 +108,15 @@ class LogEntryTestPeer { ...@@ -107,14 +108,15 @@ class LogEntryTestPeer {
std::string FormatLogMessage() const { std::string FormatLogMessage() const {
return log_internal::FormatLogMessage( return log_internal::FormatLogMessage(
entry_.log_severity(), ci_.cs, ci_.subsecond, entry_.tid(), entry_.log_severity(), ci_.cs, ci_.subsecond, entry_.tid(),
entry_.source_basename(), entry_.source_line(), entry_.text_message()); entry_.source_basename(), entry_.source_line(), format_,
entry_.text_message());
} }
std::string FormatPrefixIntoSizedBuffer(size_t sz) { std::string FormatPrefixIntoSizedBuffer(size_t sz) {
std::string str(sz, '\0'); std::string str(sz, '\0');
absl::Span<char> buf(&str[0], str.size()); absl::Span<char> buf(&str[0], str.size());
const size_t prefix_size = log_internal::FormatLogPrefix( const size_t prefix_size = log_internal::FormatLogPrefix(
entry_.log_severity(), entry_.timestamp(), entry_.tid(), entry_.log_severity(), entry_.timestamp(), entry_.tid(),
entry_.source_basename(), entry_.source_line(), buf); entry_.source_basename(), entry_.source_line(), format_, buf);
EXPECT_THAT(prefix_size, Eq(static_cast<size_t>(buf.data() - str.data()))); EXPECT_THAT(prefix_size, Eq(static_cast<size_t>(buf.data() - str.data())));
str.resize(prefix_size); str.resize(prefix_size);
return str; return str;
...@@ -123,6 +125,7 @@ class LogEntryTestPeer { ...@@ -123,6 +125,7 @@ class LogEntryTestPeer {
private: private:
absl::LogEntry entry_; absl::LogEntry entry_;
PrefixFormat format_;
absl::TimeZone::CivilInfo ci_; absl::TimeZone::CivilInfo ci_;
std::vector<char> buf_; std::vector<char> buf_;
}; };
...@@ -136,7 +139,9 @@ constexpr bool kUsePrefix = true, kNoPrefix = false; ...@@ -136,7 +139,9 @@ constexpr bool kUsePrefix = true, kNoPrefix = false;
TEST(LogEntryTest, Baseline) { TEST(LogEntryTest, Baseline) {
LogEntryTestPeer entry("foo.cc", 1234, kUsePrefix, absl::LogSeverity::kInfo, LogEntryTestPeer entry("foo.cc", 1234, kUsePrefix, absl::LogSeverity::kInfo,
"2020-01-02T03:04:05.6789", 451, "hello world"); "2020-01-02T03:04:05.6789", 451,
absl::log_internal::PrefixFormat::kNotRaw,
"hello world");
EXPECT_THAT(entry.FormatLogMessage(), EXPECT_THAT(entry.FormatLogMessage(),
Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world")); Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world"));
EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
...@@ -158,7 +163,9 @@ TEST(LogEntryTest, Baseline) { ...@@ -158,7 +163,9 @@ TEST(LogEntryTest, Baseline) {
TEST(LogEntryTest, NoPrefix) { TEST(LogEntryTest, NoPrefix) {
LogEntryTestPeer entry("foo.cc", 1234, kNoPrefix, absl::LogSeverity::kInfo, LogEntryTestPeer entry("foo.cc", 1234, kNoPrefix, absl::LogSeverity::kInfo,
"2020-01-02T03:04:05.6789", 451, "hello world"); "2020-01-02T03:04:05.6789", 451,
absl::log_internal::PrefixFormat::kNotRaw,
"hello world");
EXPECT_THAT(entry.FormatLogMessage(), EXPECT_THAT(entry.FormatLogMessage(),
Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world")); Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world"));
// These methods are not responsible for honoring `prefix()`. // These methods are not responsible for honoring `prefix()`.
...@@ -179,7 +186,8 @@ TEST(LogEntryTest, NoPrefix) { ...@@ -179,7 +186,8 @@ TEST(LogEntryTest, NoPrefix) {
TEST(LogEntryTest, EmptyFields) { TEST(LogEntryTest, EmptyFields) {
LogEntryTestPeer entry("", 0, kUsePrefix, absl::LogSeverity::kInfo, LogEntryTestPeer entry("", 0, kUsePrefix, absl::LogSeverity::kInfo,
"2020-01-02T03:04:05", 0, ""); "2020-01-02T03:04:05", 0,
absl::log_internal::PrefixFormat::kNotRaw, "");
const std::string format_message = entry.FormatLogMessage(); const std::string format_message = entry.FormatLogMessage();
EXPECT_THAT(format_message, Eq("I0102 03:04:05.000000 0 :0] ")); EXPECT_THAT(format_message, Eq("I0102 03:04:05.000000 0 :0] "));
EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq(format_message)); EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq(format_message));
...@@ -201,10 +209,10 @@ TEST(LogEntryTest, NegativeFields) { ...@@ -201,10 +209,10 @@ TEST(LogEntryTest, NegativeFields) {
// When Abseil's minimum C++ version is C++17, this conditional can be // When Abseil's minimum C++ version is C++17, this conditional can be
// converted to a constexpr if and the static_cast below removed. // converted to a constexpr if and the static_cast below removed.
if (std::is_signed<absl::LogEntry::tid_t>::value) { if (std::is_signed<absl::LogEntry::tid_t>::value) {
LogEntryTestPeer entry("foo.cc", -1234, kUsePrefix, LogEntryTestPeer entry(
absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789", "foo.cc", -1234, kUsePrefix, absl::LogSeverity::kInfo,
static_cast<absl::LogEntry::tid_t>(-451), "2020-01-02T03:04:05.6789", static_cast<absl::LogEntry::tid_t>(-451),
"hello world"); absl::log_internal::PrefixFormat::kNotRaw, "hello world");
EXPECT_THAT(entry.FormatLogMessage(), EXPECT_THAT(entry.FormatLogMessage(),
Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] hello world")); Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] hello world"));
EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
...@@ -227,7 +235,8 @@ TEST(LogEntryTest, NegativeFields) { ...@@ -227,7 +235,8 @@ TEST(LogEntryTest, NegativeFields) {
} else { } else {
LogEntryTestPeer entry("foo.cc", -1234, kUsePrefix, LogEntryTestPeer entry("foo.cc", -1234, kUsePrefix,
absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789", absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789",
451, "hello world"); 451, absl::log_internal::PrefixFormat::kNotRaw,
"hello world");
EXPECT_THAT(entry.FormatLogMessage(), EXPECT_THAT(entry.FormatLogMessage(),
Eq("I0102 03:04:05.678900 451 foo.cc:-1234] hello world")); Eq("I0102 03:04:05.678900 451 foo.cc:-1234] hello world"));
EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
...@@ -256,6 +265,7 @@ TEST(LogEntryTest, LongFields) { ...@@ -256,6 +265,7 @@ TEST(LogEntryTest, LongFields) {
"I've information vegetable, animal, and mineral.", "I've information vegetable, animal, and mineral.",
2147483647, kUsePrefix, absl::LogSeverity::kInfo, 2147483647, kUsePrefix, absl::LogSeverity::kInfo,
"2020-01-02T03:04:05.678967896789", 2147483647, "2020-01-02T03:04:05.678967896789", 2147483647,
absl::log_internal::PrefixFormat::kNotRaw,
"I know the kings of England, and I quote the fights historical / " "I know the kings of England, and I quote the fights historical / "
"From Marathon to Waterloo, in order categorical."); "From Marathon to Waterloo, in order categorical.");
EXPECT_THAT(entry.FormatLogMessage(), EXPECT_THAT(entry.FormatLogMessage(),
...@@ -315,6 +325,7 @@ TEST(LogEntryTest, LongNegativeFields) { ...@@ -315,6 +325,7 @@ TEST(LogEntryTest, LongNegativeFields) {
-2147483647, kUsePrefix, absl::LogSeverity::kInfo, -2147483647, kUsePrefix, absl::LogSeverity::kInfo,
"2020-01-02T03:04:05.678967896789", "2020-01-02T03:04:05.678967896789",
static_cast<absl::LogEntry::tid_t>(-2147483647), static_cast<absl::LogEntry::tid_t>(-2147483647),
absl::log_internal::PrefixFormat::kNotRaw,
"I know the kings of England, and I quote the fights historical / " "I know the kings of England, and I quote the fights historical / "
"From Marathon to Waterloo, in order categorical."); "From Marathon to Waterloo, in order categorical.");
EXPECT_THAT( EXPECT_THAT(
...@@ -372,6 +383,7 @@ TEST(LogEntryTest, LongNegativeFields) { ...@@ -372,6 +383,7 @@ TEST(LogEntryTest, LongNegativeFields) {
"I've information vegetable, animal, and mineral.", "I've information vegetable, animal, and mineral.",
-2147483647, kUsePrefix, absl::LogSeverity::kInfo, -2147483647, kUsePrefix, absl::LogSeverity::kInfo,
"2020-01-02T03:04:05.678967896789", 2147483647, "2020-01-02T03:04:05.678967896789", 2147483647,
absl::log_internal::PrefixFormat::kNotRaw,
"I know the kings of England, and I quote the fights historical / " "I know the kings of England, and I quote the fights historical / "
"From Marathon to Waterloo, in order categorical."); "From Marathon to Waterloo, in order categorical.");
EXPECT_THAT( EXPECT_THAT(
...@@ -426,4 +438,31 @@ TEST(LogEntryTest, LongNegativeFields) { ...@@ -426,4 +438,31 @@ TEST(LogEntryTest, LongNegativeFields) {
} }
} }
TEST(LogEntryTest, Raw) {
LogEntryTestPeer entry("foo.cc", 1234, kUsePrefix, absl::LogSeverity::kInfo,
"2020-01-02T03:04:05.6789", 451,
absl::log_internal::PrefixFormat::kRaw, "hello world");
EXPECT_THAT(
entry.FormatLogMessage(),
Eq("I0102 03:04:05.678900 451 foo.cc:1234] RAW: hello world"));
EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
Eq("I0102 03:04:05.678900 451 foo.cc:1234] RAW: "));
for (size_t sz =
strlen("I0102 03:04:05.678900 451 foo.cc:1234] RAW: ") + 20;
sz != std::numeric_limits<size_t>::max(); sz--)
EXPECT_THAT("I0102 03:04:05.678900 451 foo.cc:1234] RAW: ",
StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
EXPECT_THAT(
entry.entry().text_message_with_prefix_and_newline(),
Eq("I0102 03:04:05.678900 451 foo.cc:1234] RAW: hello world\n"));
EXPECT_THAT(
entry.entry().text_message_with_prefix_and_newline_c_str(),
StrEq("I0102 03:04:05.678900 451 foo.cc:1234] RAW: hello world\n"));
EXPECT_THAT(
entry.entry().text_message_with_prefix(),
Eq("I0102 03:04:05.678900 451 foo.cc:1234] RAW: hello world"));
EXPECT_THAT(entry.entry().text_message(), Eq("hello world"));
}
} // 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