1 //
2 // Copyright 2022 The Abseil Authors.
3 //
4 // Licensed under the Apache License, Version 2.0 (the "License");
5 // you may not use this file except in compliance with the License.
6 // You may obtain a copy of the License at
7 //
8 // https://www.apache.org/licenses/LICENSE-2.0
9 //
10 // Unless required by applicable law or agreed to in writing, software
11 // distributed under the License is distributed on an "AS IS" BASIS,
12 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 // See the License for the specific language governing permissions and
14 // limitations under the License.
15
16 #include "absl/log/log_entry.h"
17
18 #include <stddef.h>
19 #include <stdint.h>
20
21 #include <cstring>
22 #include <limits>
23 #include <string>
24 #include <type_traits>
25 #include <utility>
26 #include <vector>
27
28 #include "gmock/gmock.h"
29 #include "gtest/gtest.h"
30 #include "absl/base/attributes.h"
31 #include "absl/base/config.h"
32 #include "absl/base/log_severity.h"
33 #include "absl/log/internal/log_format.h"
34 #include "absl/log/internal/test_helpers.h"
35 #include "absl/strings/numbers.h"
36 #include "absl/strings/str_split.h"
37 #include "absl/strings/string_view.h"
38 #include "absl/time/civil_time.h"
39 #include "absl/time/time.h"
40 #include "absl/types/span.h"
41
42 namespace {
43
44 using ::absl::log_internal::LogEntryTestPeer;
45 using ::testing::Eq;
46 using ::testing::IsTrue;
47 using ::testing::StartsWith;
48 using ::testing::StrEq;
49
50 auto* test_env ABSL_ATTRIBUTE_UNUSED = ::testing::AddGlobalTestEnvironment(
51 new absl::log_internal::LogTestEnvironment);
52
53 // Copies into `dst` as many bytes of `src` as will fit, then truncates the
54 // copied bytes from the front of `dst` and returns the number of bytes written.
AppendTruncated(absl::string_view src,absl::Span<char> & dst)55 size_t AppendTruncated(absl::string_view src, absl::Span<char>& dst) {
56 if (src.size() > dst.size()) src = src.substr(0, dst.size());
57 memcpy(dst.data(), src.data(), src.size());
58 dst.remove_prefix(src.size());
59 return src.size();
60 }
61
62 } // namespace
63
64 namespace absl {
65 ABSL_NAMESPACE_BEGIN
66 namespace log_internal {
67
68 class LogEntryTestPeer {
69 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)70 LogEntryTestPeer(absl::string_view base_filename, int line, bool prefix,
71 absl::LogSeverity severity, absl::string_view timestamp,
72 absl::LogEntry::tid_t tid, absl::string_view text_message)
73 : buf_(15000, '\0') {
74 entry_.base_filename_ = base_filename;
75 entry_.line_ = line;
76 entry_.prefix_ = prefix;
77 entry_.severity_ = severity;
78 std::string time_err;
79 EXPECT_THAT(
80 absl::ParseTime("%Y-%m-%d%ET%H:%M:%E*S", timestamp,
81 absl::LocalTimeZone(), &entry_.timestamp_, &time_err),
82 IsTrue())
83 << "Failed to parse time " << timestamp << ": " << time_err;
84 entry_.tid_ = tid;
85 std::pair<absl::string_view, std::string> timestamp_bits =
86 absl::StrSplit(timestamp, absl::ByChar('.'));
87 EXPECT_THAT(absl::ParseCivilTime(timestamp_bits.first, &ci_.cs), IsTrue())
88 << "Failed to parse time " << timestamp_bits.first;
89 timestamp_bits.second.resize(9, '0');
90 int64_t nanos = 0;
91 EXPECT_THAT(absl::SimpleAtoi(timestamp_bits.second, &nanos), IsTrue())
92 << "Failed to parse time " << timestamp_bits.first;
93 ci_.subsecond = absl::Nanoseconds(nanos);
94
95 absl::Span<char> view = absl::MakeSpan(buf_);
96 view.remove_suffix(2);
97 entry_.prefix_len_ =
98 entry_.prefix_
99 ? log_internal::FormatLogPrefix(
100 entry_.log_severity(), entry_.timestamp(), entry_.tid(),
101 entry_.source_basename(), entry_.source_line(), view)
102 : 0;
103
104 EXPECT_THAT(entry_.prefix_len_,
105 Eq(static_cast<size_t>(view.data() - buf_.data())));
106 AppendTruncated(text_message, view);
107 view = absl::Span<char>(view.data(), view.size() + 2);
108 view[0] = '\n';
109 view[1] = '\0';
110 view.remove_prefix(2);
111 buf_.resize(static_cast<size_t>(view.data() - buf_.data()));
112 entry_.text_message_with_prefix_and_newline_and_nul_ = absl::MakeSpan(buf_);
113 }
114 LogEntryTestPeer(const LogEntryTestPeer&) = delete;
115 LogEntryTestPeer& operator=(const LogEntryTestPeer&) = delete;
116
FormatLogMessage() const117 std::string FormatLogMessage() const {
118 return log_internal::FormatLogMessage(
119 entry_.log_severity(), ci_.cs, ci_.subsecond, entry_.tid(),
120 entry_.source_basename(), entry_.source_line(), entry_.text_message());
121 }
FormatPrefixIntoSizedBuffer(size_t sz)122 std::string FormatPrefixIntoSizedBuffer(size_t sz) {
123 std::string str(sz, '\0');
124 absl::Span<char> buf(&str[0], str.size());
125 const size_t prefix_size = log_internal::FormatLogPrefix(
126 entry_.log_severity(), entry_.timestamp(), entry_.tid(),
127 entry_.source_basename(), entry_.source_line(), buf);
128 EXPECT_THAT(prefix_size, Eq(static_cast<size_t>(buf.data() - str.data())));
129 str.resize(prefix_size);
130 return str;
131 }
entry() const132 const absl::LogEntry& entry() const { return entry_; }
133
134 private:
135 absl::LogEntry entry_;
136 absl::TimeZone::CivilInfo ci_;
137 std::vector<char> buf_;
138 };
139
140 } // namespace log_internal
141 ABSL_NAMESPACE_END
142 } // namespace absl
143
144 namespace {
145 constexpr bool kUsePrefix = true, kNoPrefix = false;
146
TEST(LogEntryTest,Baseline)147 TEST(LogEntryTest, Baseline) {
148 LogEntryTestPeer entry("foo.cc", 1234, kUsePrefix, absl::LogSeverity::kInfo,
149 "2020-01-02T03:04:05.6789", 451, "hello world");
150 EXPECT_THAT(entry.FormatLogMessage(),
151 Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world"));
152 EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
153 Eq("I0102 03:04:05.678900 451 foo.cc:1234] "));
154 for (size_t sz = strlen("I0102 03:04:05.678900 451 foo.cc:1234] ") + 20;
155 sz != std::numeric_limits<size_t>::max(); sz--)
156 EXPECT_THAT("I0102 03:04:05.678900 451 foo.cc:1234] ",
157 StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
158
159 EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline(),
160 Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world\n"));
161 EXPECT_THAT(
162 entry.entry().text_message_with_prefix_and_newline_c_str(),
163 StrEq("I0102 03:04:05.678900 451 foo.cc:1234] hello world\n"));
164 EXPECT_THAT(entry.entry().text_message_with_prefix(),
165 Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world"));
166 EXPECT_THAT(entry.entry().text_message(), Eq("hello world"));
167 }
168
TEST(LogEntryTest,NoPrefix)169 TEST(LogEntryTest, NoPrefix) {
170 LogEntryTestPeer entry("foo.cc", 1234, kNoPrefix, absl::LogSeverity::kInfo,
171 "2020-01-02T03:04:05.6789", 451, "hello world");
172 EXPECT_THAT(entry.FormatLogMessage(),
173 Eq("I0102 03:04:05.678900 451 foo.cc:1234] hello world"));
174 // These methods are not responsible for honoring `prefix()`.
175 EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
176 Eq("I0102 03:04:05.678900 451 foo.cc:1234] "));
177 for (size_t sz = strlen("I0102 03:04:05.678900 451 foo.cc:1234] ") + 20;
178 sz != std::numeric_limits<size_t>::max(); sz--)
179 EXPECT_THAT("I0102 03:04:05.678900 451 foo.cc:1234] ",
180 StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
181
182 EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline(),
183 Eq("hello world\n"));
184 EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline_c_str(),
185 StrEq("hello world\n"));
186 EXPECT_THAT(entry.entry().text_message_with_prefix(), Eq("hello world"));
187 EXPECT_THAT(entry.entry().text_message(), Eq("hello world"));
188 }
189
TEST(LogEntryTest,EmptyFields)190 TEST(LogEntryTest, EmptyFields) {
191 LogEntryTestPeer entry("", 0, kUsePrefix, absl::LogSeverity::kInfo,
192 "2020-01-02T03:04:05", 0, "");
193 const std::string format_message = entry.FormatLogMessage();
194 EXPECT_THAT(format_message, Eq("I0102 03:04:05.000000 0 :0] "));
195 EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000), Eq(format_message));
196 for (size_t sz = format_message.size() + 20;
197 sz != std::numeric_limits<size_t>::max(); sz--)
198 EXPECT_THAT(format_message,
199 StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
200
201 EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline(),
202 Eq("I0102 03:04:05.000000 0 :0] \n"));
203 EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline_c_str(),
204 StrEq("I0102 03:04:05.000000 0 :0] \n"));
205 EXPECT_THAT(entry.entry().text_message_with_prefix(),
206 Eq("I0102 03:04:05.000000 0 :0] "));
207 EXPECT_THAT(entry.entry().text_message(), Eq(""));
208 }
209
TEST(LogEntryTest,NegativeFields)210 TEST(LogEntryTest, NegativeFields) {
211 // When Abseil's minimum C++ version is C++17, this conditional can be
212 // converted to a constexpr if and the static_cast below removed.
213 if (std::is_signed<absl::LogEntry::tid_t>::value) {
214 LogEntryTestPeer entry("foo.cc", -1234, kUsePrefix,
215 absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789",
216 static_cast<absl::LogEntry::tid_t>(-451),
217 "hello world");
218 EXPECT_THAT(entry.FormatLogMessage(),
219 Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] hello world"));
220 EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
221 Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] "));
222 for (size_t sz =
223 strlen("I0102 03:04:05.678900 -451 foo.cc:-1234] ") + 20;
224 sz != std::numeric_limits<size_t>::max(); sz--)
225 EXPECT_THAT("I0102 03:04:05.678900 -451 foo.cc:-1234] ",
226 StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
227
228 EXPECT_THAT(
229 entry.entry().text_message_with_prefix_and_newline(),
230 Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] hello world\n"));
231 EXPECT_THAT(
232 entry.entry().text_message_with_prefix_and_newline_c_str(),
233 StrEq("I0102 03:04:05.678900 -451 foo.cc:-1234] hello world\n"));
234 EXPECT_THAT(entry.entry().text_message_with_prefix(),
235 Eq("I0102 03:04:05.678900 -451 foo.cc:-1234] hello world"));
236 EXPECT_THAT(entry.entry().text_message(), Eq("hello world"));
237 } else {
238 LogEntryTestPeer entry("foo.cc", -1234, kUsePrefix,
239 absl::LogSeverity::kInfo, "2020-01-02T03:04:05.6789",
240 451, "hello world");
241 EXPECT_THAT(entry.FormatLogMessage(),
242 Eq("I0102 03:04:05.678900 451 foo.cc:-1234] hello world"));
243 EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
244 Eq("I0102 03:04:05.678900 451 foo.cc:-1234] "));
245 for (size_t sz =
246 strlen("I0102 03:04:05.678900 451 foo.cc:-1234] ") + 20;
247 sz != std::numeric_limits<size_t>::max(); sz--)
248 EXPECT_THAT("I0102 03:04:05.678900 451 foo.cc:-1234] ",
249 StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
250
251 EXPECT_THAT(
252 entry.entry().text_message_with_prefix_and_newline(),
253 Eq("I0102 03:04:05.678900 451 foo.cc:-1234] hello world\n"));
254 EXPECT_THAT(
255 entry.entry().text_message_with_prefix_and_newline_c_str(),
256 StrEq("I0102 03:04:05.678900 451 foo.cc:-1234] hello world\n"));
257 EXPECT_THAT(entry.entry().text_message_with_prefix(),
258 Eq("I0102 03:04:05.678900 451 foo.cc:-1234] hello world"));
259 EXPECT_THAT(entry.entry().text_message(), Eq("hello world"));
260 }
261 }
262
TEST(LogEntryTest,LongFields)263 TEST(LogEntryTest, LongFields) {
264 LogEntryTestPeer entry(
265 "I am the very model of a modern Major-General / "
266 "I've information vegetable, animal, and mineral.",
267 2147483647, kUsePrefix, absl::LogSeverity::kInfo,
268 "2020-01-02T03:04:05.678967896789", 2147483647,
269 "I know the kings of England, and I quote the fights historical / "
270 "From Marathon to Waterloo, in order categorical.");
271 EXPECT_THAT(entry.FormatLogMessage(),
272 Eq("I0102 03:04:05.678967 2147483647 I am the very model of a "
273 "modern Major-General / I've information vegetable, animal, "
274 "and mineral.:2147483647] I know the kings of England, and I "
275 "quote the fights historical / From Marathon to Waterloo, in "
276 "order categorical."));
277 EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
278 Eq("I0102 03:04:05.678967 2147483647 I am the very model of a "
279 "modern Major-General / I've information vegetable, animal, "
280 "and mineral.:2147483647] "));
281 for (size_t sz =
282 strlen("I0102 03:04:05.678967 2147483647 I am the very model of a "
283 "modern Major-General / I've information vegetable, animal, "
284 "and mineral.:2147483647] ") +
285 20;
286 sz != std::numeric_limits<size_t>::max(); sz--)
287 EXPECT_THAT(
288 "I0102 03:04:05.678967 2147483647 I am the very model of a "
289 "modern Major-General / I've information vegetable, animal, "
290 "and mineral.:2147483647] ",
291 StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
292
293 EXPECT_THAT(entry.entry().text_message_with_prefix_and_newline(),
294 Eq("I0102 03:04:05.678967 2147483647 I am the very model of a "
295 "modern Major-General / I've information vegetable, animal, "
296 "and mineral.:2147483647] I know the kings of England, and I "
297 "quote the fights historical / From Marathon to Waterloo, in "
298 "order categorical.\n"));
299 EXPECT_THAT(
300 entry.entry().text_message_with_prefix_and_newline_c_str(),
301 StrEq("I0102 03:04:05.678967 2147483647 I am the very model of a "
302 "modern Major-General / I've information vegetable, animal, "
303 "and mineral.:2147483647] I know the kings of England, and I "
304 "quote the fights historical / From Marathon to Waterloo, in "
305 "order categorical.\n"));
306 EXPECT_THAT(entry.entry().text_message_with_prefix(),
307 Eq("I0102 03:04:05.678967 2147483647 I am the very model of a "
308 "modern Major-General / I've information vegetable, animal, "
309 "and mineral.:2147483647] I know the kings of England, and I "
310 "quote the fights historical / From Marathon to Waterloo, in "
311 "order categorical."));
312 EXPECT_THAT(
313 entry.entry().text_message(),
314 Eq("I know the kings of England, and I quote the fights historical / "
315 "From Marathon to Waterloo, in order categorical."));
316 }
317
TEST(LogEntryTest,LongNegativeFields)318 TEST(LogEntryTest, LongNegativeFields) {
319 // When Abseil's minimum C++ version is C++17, this conditional can be
320 // converted to a constexpr if and the static_cast below removed.
321 if (std::is_signed<absl::LogEntry::tid_t>::value) {
322 LogEntryTestPeer entry(
323 "I am the very model of a modern Major-General / "
324 "I've information vegetable, animal, and mineral.",
325 -2147483647, kUsePrefix, absl::LogSeverity::kInfo,
326 "2020-01-02T03:04:05.678967896789",
327 static_cast<absl::LogEntry::tid_t>(-2147483647),
328 "I know the kings of England, and I quote the fights historical / "
329 "From Marathon to Waterloo, in order categorical.");
330 EXPECT_THAT(
331 entry.FormatLogMessage(),
332 Eq("I0102 03:04:05.678967 -2147483647 I am the very model of a "
333 "modern Major-General / I've information vegetable, animal, "
334 "and mineral.:-2147483647] I know the kings of England, and I "
335 "quote the fights historical / From Marathon to Waterloo, in "
336 "order categorical."));
337 EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
338 Eq("I0102 03:04:05.678967 -2147483647 I am the very model of a "
339 "modern Major-General / I've information vegetable, animal, "
340 "and mineral.:-2147483647] "));
341 for (size_t sz =
342 strlen(
343 "I0102 03:04:05.678967 -2147483647 I am the very model of a "
344 "modern Major-General / I've information vegetable, animal, "
345 "and mineral.:-2147483647] ") +
346 20;
347 sz != std::numeric_limits<size_t>::max(); sz--)
348 EXPECT_THAT(
349 "I0102 03:04:05.678967 -2147483647 I am the very model of a "
350 "modern Major-General / I've information vegetable, animal, "
351 "and mineral.:-2147483647] ",
352 StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
353
354 EXPECT_THAT(
355 entry.entry().text_message_with_prefix_and_newline(),
356 Eq("I0102 03:04:05.678967 -2147483647 I am the very model of a "
357 "modern Major-General / I've information vegetable, animal, "
358 "and mineral.:-2147483647] I know the kings of England, and I "
359 "quote the fights historical / From Marathon to Waterloo, in "
360 "order categorical.\n"));
361 EXPECT_THAT(
362 entry.entry().text_message_with_prefix_and_newline_c_str(),
363 StrEq("I0102 03:04:05.678967 -2147483647 I am the very model of a "
364 "modern Major-General / I've information vegetable, animal, "
365 "and mineral.:-2147483647] I know the kings of England, and I "
366 "quote the fights historical / From Marathon to Waterloo, in "
367 "order categorical.\n"));
368 EXPECT_THAT(
369 entry.entry().text_message_with_prefix(),
370 Eq("I0102 03:04:05.678967 -2147483647 I am the very model of a "
371 "modern Major-General / I've information vegetable, animal, "
372 "and mineral.:-2147483647] I know the kings of England, and I "
373 "quote the fights historical / From Marathon to Waterloo, in "
374 "order categorical."));
375 EXPECT_THAT(
376 entry.entry().text_message(),
377 Eq("I know the kings of England, and I quote the fights historical / "
378 "From Marathon to Waterloo, in order categorical."));
379 } else {
380 LogEntryTestPeer entry(
381 "I am the very model of a modern Major-General / "
382 "I've information vegetable, animal, and mineral.",
383 -2147483647, kUsePrefix, absl::LogSeverity::kInfo,
384 "2020-01-02T03:04:05.678967896789", 2147483647,
385 "I know the kings of England, and I quote the fights historical / "
386 "From Marathon to Waterloo, in order categorical.");
387 EXPECT_THAT(
388 entry.FormatLogMessage(),
389 Eq("I0102 03:04:05.678967 2147483647 I am the very model of a "
390 "modern Major-General / I've information vegetable, animal, "
391 "and mineral.:-2147483647] I know the kings of England, and I "
392 "quote the fights historical / From Marathon to Waterloo, in "
393 "order categorical."));
394 EXPECT_THAT(entry.FormatPrefixIntoSizedBuffer(1000),
395 Eq("I0102 03:04:05.678967 2147483647 I am the very model of a "
396 "modern Major-General / I've information vegetable, animal, "
397 "and mineral.:-2147483647] "));
398 for (size_t sz =
399 strlen(
400 "I0102 03:04:05.678967 2147483647 I am the very model of a "
401 "modern Major-General / I've information vegetable, animal, "
402 "and mineral.:-2147483647] ") +
403 20;
404 sz != std::numeric_limits<size_t>::max(); sz--)
405 EXPECT_THAT(
406 "I0102 03:04:05.678967 2147483647 I am the very model of a "
407 "modern Major-General / I've information vegetable, animal, "
408 "and mineral.:-2147483647] ",
409 StartsWith(entry.FormatPrefixIntoSizedBuffer(sz)));
410
411 EXPECT_THAT(
412 entry.entry().text_message_with_prefix_and_newline(),
413 Eq("I0102 03:04:05.678967 2147483647 I am the very model of a "
414 "modern Major-General / I've information vegetable, animal, "
415 "and mineral.:-2147483647] I know the kings of England, and I "
416 "quote the fights historical / From Marathon to Waterloo, in "
417 "order categorical.\n"));
418 EXPECT_THAT(
419 entry.entry().text_message_with_prefix_and_newline_c_str(),
420 StrEq("I0102 03:04:05.678967 2147483647 I am the very model of a "
421 "modern Major-General / I've information vegetable, animal, "
422 "and mineral.:-2147483647] I know the kings of England, and I "
423 "quote the fights historical / From Marathon to Waterloo, in "
424 "order categorical.\n"));
425 EXPECT_THAT(
426 entry.entry().text_message_with_prefix(),
427 Eq("I0102 03:04:05.678967 2147483647 I am the very model of a "
428 "modern Major-General / I've information vegetable, animal, "
429 "and mineral.:-2147483647] I know the kings of England, and I "
430 "quote the fights historical / From Marathon to Waterloo, in "
431 "order categorical."));
432 EXPECT_THAT(
433 entry.entry().text_message(),
434 Eq("I know the kings of England, and I quote the fights historical / "
435 "From Marathon to Waterloo, in order categorical."));
436 }
437 }
438
439 } // namespace
440