// // Copyright 2022 The Abseil Authors. // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. // You may obtain a copy of the License at // // https://www.apache.org/licenses/LICENSE-2.0 // // Unless required by applicable law or agreed to in writing, software // distributed under the License is distributed on an "AS IS" BASIS, // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. // See the License for the specific language governing permissions and // limitations under the License. #include "absl/log/log_entry.h" #include #include #include #include #include #include #include #include #include "gmock/gmock.h" #include "gtest/gtest.h" #include "absl/base/attributes.h" #include "absl/base/config.h" #include "absl/base/log_severity.h" #include "absl/log/internal/log_format.h" #include "absl/log/internal/test_helpers.h" #include "absl/strings/numbers.h" #include "absl/strings/str_split.h" #include "absl/strings/string_view.h" #include "absl/time/civil_time.h" #include "absl/time/time.h" #include "absl/types/span.h" namespace { using ::absl::log_internal::LogEntryTestPeer; using ::testing::Eq; using ::testing::IsTrue; using ::testing::StartsWith; using ::testing::StrEq; auto* test_env ABSL_ATTRIBUTE_UNUSED = ::testing::AddGlobalTestEnvironment( new absl::log_internal::LogTestEnvironment); // Copies into `dst` as many bytes of `src` as will fit, then truncates the // copied bytes from the front of `dst` and returns the number of bytes written. size_t AppendTruncated(absl::string_view src, absl::Span& dst) { if (src.size() > dst.size()) src = src.substr(0, dst.size()); memcpy(dst.data(), src.data(), src.size()); dst.remove_prefix(src.size()); return src.size(); } } // namespace namespace absl { ABSL_NAMESPACE_BEGIN namespace log_internal { class LogEntryTestPeer { public: LogEntryTestPeer(absl::string_view base_filename, int line, bool prefix, absl::LogSeverity severity, absl::string_view timestamp, absl::LogEntry::tid_t tid, absl::string_view text_message) : buf_(15000, '\0') { entry_.base_filename_ = base_filename; entry_.line_ = line; entry_.prefix_ = prefix; entry_.severity_ = severity; std::string time_err; EXPECT_THAT( absl::ParseTime("%Y-%m-%d%ET%H:%M:%E*S", timestamp, absl::LocalTimeZone(), &entry_.timestamp_, &time_err), IsTrue()) << "Failed to parse time " << timestamp << ": " << time_err; entry_.tid_ = tid; std::pair timestamp_bits = absl::StrSplit(timestamp, absl::ByChar('.')); EXPECT_THAT(absl::ParseCivilTime(timestamp_bits.first, &ci_.cs), IsTrue()) << "Failed to parse time " << timestamp_bits.first; timestamp_bits.second.resize(9, '0'); int64_t nanos = 0; EXPECT_THAT(absl::SimpleAtoi(timestamp_bits.second, &nanos), IsTrue()) << "Failed to parse time " << timestamp_bits.first; ci_.subsecond = absl::Nanoseconds(nanos); absl::Span view = absl::MakeSpan(buf_); view.remove_suffix(2); entry_.prefix_len_ = entry_.prefix_ ? log_internal::FormatLogPrefix( entry_.log_severity(), entry_.timestamp(), entry_.tid(), entry_.source_basename(), entry_.source_line(), view) : 0; EXPECT_THAT(entry_.prefix_len_, Eq(view.data() - buf_.data())); AppendTruncated(text_message, view); view = absl::Span(view.data(), view.size() + 2); view[0] = '\n'; view[1] = '\0'; view.remove_prefix(2); buf_.resize(view.data() - buf_.data()); entry_.text_message_with_prefix_and_newline_and_nul_ = absl::MakeSpan(buf_); } LogEntryTestPeer(const LogEntryTestPeer&) = delete; LogEntryTestPeer& operator=(const LogEntryTestPeer&) = delete; std::string FormatLogMessage() const { return log_internal::FormatLogMessage( entry_.log_severity(), ci_.cs, ci_.subsecond, entry_.tid(), entry_.source_basename(), entry_.source_line(), entry_.text_message()); } std::string FormatPrefixIntoSizedBuffer(size_t sz) { std::string str(sz, '\0'); absl::Span buf(&str[0], str.size()); const size_t prefix_size = log_internal::FormatLogPrefix( entry_.log_severity(), entry_.timestamp(), entry_.tid(), entry_.source_basename(), entry_.source_line(), buf); EXPECT_THAT(prefix_size, Eq(buf.data() - str.data())); str.resize(prefix_size); return str; } const absl::LogEntry& entry() const { return entry_; } private: absl::LogEntry entry_; absl::TimeZone::CivilInfo ci_; std::vector buf_; }; } // namespace log_internal ABSL_NAMESPACE_END } // namespace absl namespace { constexpr bool kUsePrefix = true, kNoPrefix = false; TEST(LogEntryTest, Baseline) { LogEntryTestPeer entry("foo.cc", 1234, kUsePrefix, absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789", 451, "hello world"); EXPECT_THAT(entry.FormatLogMessage(), Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world")); EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq("I0102 03:04:05.678900 451 foo.cc:1234] ")); for (size_t sz = strlen("I0102 03:04:05.678900 451 foo.cc:1234] ") + 20; sz != std::numeric_limits::max(); sz--) EXPECT_THAT("I0102 03:04:05.678900 451 foo.cc:1234] ", StartsWith(entry.FormatPrefixIntoSizedBuffer(sz))); EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline(), Eq("I0102 03:04:05.678900 451 foo.cc:1234] 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] hello world\n")); EXPECT_THAT(entry.entry().text_message_with_prefix(), Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world")); EXPECT_THAT(entry.entry().text_message(), Eq("hello world")); } TEST(LogEntryTest, NoPrefix) { LogEntryTestPeer entry("foo.cc", 1234, kNoPrefix, absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789", 451, "hello world"); EXPECT_THAT(entry.FormatLogMessage(), Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world")); // These methods are not responsible for honoring `prefix()`. EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq("I0102 03:04:05.678900 451 foo.cc:1234] ")); for (size_t sz = strlen("I0102 03:04:05.678900 451 foo.cc:1234] ") + 20; sz != std::numeric_limits::max(); sz--) EXPECT_THAT("I0102 03:04:05.678900 451 foo.cc:1234] ", StartsWith(entry.FormatPrefixIntoSizedBuffer(sz))); EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline(), Eq("hello world\n")); EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline_c_str(), StrEq("hello world\n")); EXPECT_THAT(entry.entry().text_message_with_prefix(), Eq("hello world")); EXPECT_THAT(entry.entry().text_message(), Eq("hello world")); } TEST(LogEntryTest, EmptyFields) { LogEntryTestPeer entry("", 0, kUsePrefix, absl::LogSeverity::kInfo, "2020-01-02T03:04:05", 0, ""); const std::string format_message = entry.FormatLogMessage(); EXPECT_THAT(format_message, Eq("I0102 03:04:05.000000 0 :0] ")); EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq(format_message)); for (size_t sz = format_message.size() + 20; sz != std::numeric_limits::max(); sz--) EXPECT_THAT(format_message, StartsWith(entry.FormatPrefixIntoSizedBuffer(sz))); EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline(), Eq("I0102 03:04:05.000000 0 :0] \n")); EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline_c_str(), StrEq("I0102 03:04:05.000000 0 :0] \n")); EXPECT_THAT(entry.entry().text_message_with_prefix(), Eq("I0102 03:04:05.000000 0 :0] ")); EXPECT_THAT(entry.entry().text_message(), Eq("")); } TEST(LogEntryTest, NegativeFields) { if (std::is_signed::value) { LogEntryTestPeer entry("foo.cc", -1234, kUsePrefix, absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789", -451, "hello world"); EXPECT_THAT(entry.FormatLogMessage(), Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] hello world")); EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] ")); for (size_t sz = strlen("I0102 03:04:05.678900 -451 foo.cc:-1234] ") + 20; sz != std::numeric_limits::max(); sz--) EXPECT_THAT("I0102 03:04:05.678900 -451 foo.cc:-1234] ", StartsWith(entry.FormatPrefixIntoSizedBuffer(sz))); EXPECT_THAT( entry.entry().text_message_with_prefix_and_newline(), Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] 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] hello world\n")); EXPECT_THAT(entry.entry().text_message_with_prefix(), Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] hello world")); EXPECT_THAT(entry.entry().text_message(), Eq("hello world")); } else { LogEntryTestPeer entry("foo.cc", -1234, kUsePrefix, absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789", 451, "hello world"); EXPECT_THAT(entry.FormatLogMessage(), Eq("I0102 03:04:05.678900 451 foo.cc:-1234] hello world")); EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq("I0102 03:04:05.678900 451 foo.cc:-1234] ")); for (size_t sz = strlen("I0102 03:04:05.678900 451 foo.cc:-1234] ") + 20; sz != std::numeric_limits::max(); sz--) EXPECT_THAT("I0102 03:04:05.678900 451 foo.cc:-1234] ", StartsWith(entry.FormatPrefixIntoSizedBuffer(sz))); EXPECT_THAT( entry.entry().text_message_with_prefix_and_newline(), Eq("I0102 03:04:05.678900 451 foo.cc:-1234] 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] hello world\n")); EXPECT_THAT(entry.entry().text_message_with_prefix(), Eq("I0102 03:04:05.678900 451 foo.cc:-1234] hello world")); EXPECT_THAT(entry.entry().text_message(), Eq("hello world")); } } TEST(LogEntryTest, LongFields) { LogEntryTestPeer entry( "I am the very model of a modern Major-General / " "I've information vegetable, animal, and mineral.", 2147483647, kUsePrefix, absl::LogSeverity::kInfo, "2020-01-02T03:04:05.678967896789", 2147483647, "I know the kings of England, and I quote the fights historical / " "From Marathon to Waterloo, in order categorical."); EXPECT_THAT(entry.FormatLogMessage(), Eq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.")); EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:2147483647] ")); for (size_t sz = strlen("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:2147483647] ") + 20; sz != std::numeric_limits::max(); sz--) EXPECT_THAT( "I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:2147483647] ", StartsWith(entry.FormatPrefixIntoSizedBuffer(sz))); EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline(), Eq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.\n")); EXPECT_THAT( entry.entry().text_message_with_prefix_and_newline_c_str(), StrEq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.\n")); EXPECT_THAT(entry.entry().text_message_with_prefix(), Eq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.")); EXPECT_THAT( entry.entry().text_message(), Eq("I know the kings of England, and I quote the fights historical / " "From Marathon to Waterloo, in order categorical.")); } TEST(LogEntryTest, LongNegativeFields) { if (std::is_signed::value) { LogEntryTestPeer entry( "I am the very model of a modern Major-General / " "I've information vegetable, animal, and mineral.", -2147483647, kUsePrefix, absl::LogSeverity::kInfo, "2020-01-02T03:04:05.678967896789", -2147483647, "I know the kings of England, and I quote the fights historical / " "From Marathon to Waterloo, in order categorical."); EXPECT_THAT( entry.FormatLogMessage(), Eq("I0102 03:04:05.678967 -2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.")); EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq("I0102 03:04:05.678967 -2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] ")); for (size_t sz = strlen( "I0102 03:04:05.678967 -2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] ") + 20; sz != std::numeric_limits::max(); sz--) EXPECT_THAT( "I0102 03:04:05.678967 -2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] ", StartsWith(entry.FormatPrefixIntoSizedBuffer(sz))); EXPECT_THAT( entry.entry().text_message_with_prefix_and_newline(), Eq("I0102 03:04:05.678967 -2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.\n")); EXPECT_THAT( entry.entry().text_message_with_prefix_and_newline_c_str(), StrEq("I0102 03:04:05.678967 -2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.\n")); EXPECT_THAT( entry.entry().text_message_with_prefix(), Eq("I0102 03:04:05.678967 -2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.")); EXPECT_THAT( entry.entry().text_message(), Eq("I know the kings of England, and I quote the fights historical / " "From Marathon to Waterloo, in order categorical.")); } else { LogEntryTestPeer entry( "I am the very model of a modern Major-General / " "I've information vegetable, animal, and mineral.", -2147483647, kUsePrefix, absl::LogSeverity::kInfo, "2020-01-02T03:04:05.678967896789", 2147483647, "I know the kings of England, and I quote the fights historical / " "From Marathon to Waterloo, in order categorical."); EXPECT_THAT( entry.FormatLogMessage(), Eq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.")); EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] ")); for (size_t sz = strlen( "I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] ") + 20; sz != std::numeric_limits::max(); sz--) EXPECT_THAT( "I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] ", StartsWith(entry.FormatPrefixIntoSizedBuffer(sz))); EXPECT_THAT( entry.entry().text_message_with_prefix_and_newline(), Eq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.\n")); EXPECT_THAT( entry.entry().text_message_with_prefix_and_newline_c_str(), StrEq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.\n")); EXPECT_THAT( entry.entry().text_message_with_prefix(), Eq("I0102 03:04:05.678967 2147483647 I am the very model of a " "modern Major-General / I've information vegetable, animal, " "and mineral.:-2147483647] I know the kings of England, and I " "quote the fights historical / From Marathon to Waterloo, in " "order categorical.")); EXPECT_THAT( entry.entry().text_message(), Eq("I know the kings of England, and I quote the fights historical / " "From Marathon to Waterloo, in order categorical.")); } } } // namespace