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_streamer.h"
17
18 #include <ios>
19 #include <iostream>
20 #include <utility>
21
22 #include "gmock/gmock.h"
23 #include "gtest/gtest.h"
24 #include "absl/base/attributes.h"
25 #include "absl/base/internal/sysinfo.h"
26 #include "absl/base/log_severity.h"
27 #include "absl/log/internal/test_actions.h"
28 #include "absl/log/internal/test_helpers.h"
29 #include "absl/log/internal/test_matchers.h"
30 #include "absl/log/log.h"
31 #include "absl/log/scoped_mock_log.h"
32 #include "absl/strings/string_view.h"
33
34 namespace {
35 using ::absl::log_internal::DeathTestExpectedLogging;
36 using ::absl::log_internal::DeathTestUnexpectedLogging;
37 using ::absl::log_internal::DeathTestValidateExpectations;
38 #if GTEST_HAS_DEATH_TEST
39 using ::absl::log_internal::DiedOfFatal;
40 #endif
41 using ::absl::log_internal::InMatchWindow;
42 using ::absl::log_internal::LogSeverity;
43 using ::absl::log_internal::Prefix;
44 using ::absl::log_internal::SourceFilename;
45 using ::absl::log_internal::SourceLine;
46 using ::absl::log_internal::Stacktrace;
47 using ::absl::log_internal::TextMessage;
48 using ::absl::log_internal::ThreadID;
49 using ::absl::log_internal::Timestamp;
50 using ::testing::_;
51 using ::testing::AnyNumber;
52 using ::testing::Eq;
53 using ::testing::HasSubstr;
54 using ::testing::IsEmpty;
55 using ::testing::IsTrue;
56
57 auto* test_env ABSL_ATTRIBUTE_UNUSED = ::testing::AddGlobalTestEnvironment(
58 new absl::log_internal::LogTestEnvironment);
59
WriteToStream(absl::string_view data,std::ostream * os)60 void WriteToStream(absl::string_view data, std::ostream* os) {
61 *os << "WriteToStream: " << data;
62 }
WriteToStreamRef(absl::string_view data,std::ostream & os)63 void WriteToStreamRef(absl::string_view data, std::ostream& os) {
64 os << "WriteToStreamRef: " << data;
65 }
66
TEST(LogStreamerTest,LogInfoStreamer)67 TEST(LogStreamerTest, LogInfoStreamer) {
68 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
69
70 EXPECT_CALL(
71 test_sink,
72 Send(AllOf(
73 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
74 Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kInfo)),
75 Timestamp(InMatchWindow()),
76 ThreadID(Eq(absl::base_internal::GetTID())),
77 TextMessage(Eq("WriteToStream: foo")),
78 ENCODED_MESSAGE(MatchesEvent(
79 Eq("path/file.cc"), Eq(1234), InMatchWindow(),
80 Eq(logging::proto::INFO), Eq(absl::base_internal::GetTID()),
81 ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))),
82 Stacktrace(IsEmpty()))));
83
84 test_sink.StartCapturingLogs();
85 WriteToStream("foo", &absl::LogInfoStreamer("path/file.cc", 1234).stream());
86 }
87
TEST(LogStreamerTest,LogWarningStreamer)88 TEST(LogStreamerTest, LogWarningStreamer) {
89 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
90
91 EXPECT_CALL(
92 test_sink,
93 Send(AllOf(
94 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
95 Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kWarning)),
96 Timestamp(InMatchWindow()),
97 ThreadID(Eq(absl::base_internal::GetTID())),
98 TextMessage(Eq("WriteToStream: foo")),
99 ENCODED_MESSAGE(MatchesEvent(
100 Eq("path/file.cc"), Eq(1234), InMatchWindow(),
101 Eq(logging::proto::WARNING), Eq(absl::base_internal::GetTID()),
102 ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))),
103 Stacktrace(IsEmpty()))));
104
105 test_sink.StartCapturingLogs();
106 WriteToStream("foo",
107 &absl::LogWarningStreamer("path/file.cc", 1234).stream());
108 }
109
TEST(LogStreamerTest,LogErrorStreamer)110 TEST(LogStreamerTest, LogErrorStreamer) {
111 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
112
113 EXPECT_CALL(
114 test_sink,
115 Send(AllOf(
116 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
117 Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)),
118 Timestamp(InMatchWindow()),
119 ThreadID(Eq(absl::base_internal::GetTID())),
120 TextMessage(Eq("WriteToStream: foo")),
121 ENCODED_MESSAGE(MatchesEvent(
122 Eq("path/file.cc"), Eq(1234), InMatchWindow(),
123 Eq(logging::proto::ERROR), Eq(absl::base_internal::GetTID()),
124 ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))),
125 Stacktrace(IsEmpty()))));
126
127 test_sink.StartCapturingLogs();
128 WriteToStream("foo", &absl::LogErrorStreamer("path/file.cc", 1234).stream());
129 }
130
131 #if GTEST_HAS_DEATH_TEST
TEST(LogStreamerDeathTest,LogFatalStreamer)132 TEST(LogStreamerDeathTest, LogFatalStreamer) {
133 EXPECT_EXIT(
134 {
135 absl::ScopedMockLog test_sink;
136
137 EXPECT_CALL(test_sink, Send)
138 .Times(AnyNumber())
139 .WillRepeatedly(DeathTestUnexpectedLogging());
140
141 EXPECT_CALL(test_sink,
142 Send(AllOf(SourceFilename(Eq("path/file.cc")),
143 SourceLine(Eq(1234)), Prefix(IsTrue()),
144 LogSeverity(Eq(absl::LogSeverity::kFatal)),
145 Timestamp(InMatchWindow()),
146 ThreadID(Eq(absl::base_internal::GetTID())),
147 TextMessage(Eq("WriteToStream: foo")),
148 ENCODED_MESSAGE(MatchesEvent(
149 Eq("path/file.cc"), Eq(1234),
150 InMatchWindow(), Eq(logging::proto::FATAL),
151 Eq(absl::base_internal::GetTID()),
152 ElementsAre(EqualsProto(
153 R"pb(str: "WriteToStream: foo")pb")))))))
154 .WillOnce(DeathTestExpectedLogging());
155
156 test_sink.StartCapturingLogs();
157 WriteToStream("foo",
158 &absl::LogFatalStreamer("path/file.cc", 1234).stream());
159 },
160 DiedOfFatal, DeathTestValidateExpectations());
161 }
162 #endif
163
164 #ifdef NDEBUG
TEST(LogStreamerTest,LogDebugFatalStreamer)165 TEST(LogStreamerTest, LogDebugFatalStreamer) {
166 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
167
168 EXPECT_CALL(
169 test_sink,
170 Send(AllOf(
171 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
172 Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)),
173 Timestamp(InMatchWindow()),
174 ThreadID(Eq(absl::base_internal::GetTID())),
175 TextMessage(Eq("WriteToStream: foo")),
176 ENCODED_MESSAGE(MatchesEvent(
177 Eq("path/file.cc"), Eq(1234), InMatchWindow(),
178 Eq(logging::proto::ERROR), Eq(absl::base_internal::GetTID()),
179 ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))),
180 Stacktrace(IsEmpty()))));
181
182 test_sink.StartCapturingLogs();
183 WriteToStream("foo",
184 &absl::LogDebugFatalStreamer("path/file.cc", 1234).stream());
185 }
186 #elif GTEST_HAS_DEATH_TEST
TEST(LogStreamerDeathTest,LogDebugFatalStreamer)187 TEST(LogStreamerDeathTest, LogDebugFatalStreamer) {
188 EXPECT_EXIT(
189 {
190 absl::ScopedMockLog test_sink;
191
192 EXPECT_CALL(test_sink, Send)
193 .Times(AnyNumber())
194 .WillRepeatedly(DeathTestUnexpectedLogging());
195
196 EXPECT_CALL(test_sink,
197 Send(AllOf(SourceFilename(Eq("path/file.cc")),
198 SourceLine(Eq(1234)), Prefix(IsTrue()),
199 LogSeverity(Eq(absl::LogSeverity::kFatal)),
200 Timestamp(InMatchWindow()),
201 ThreadID(Eq(absl::base_internal::GetTID())),
202 TextMessage(Eq("WriteToStream: foo")),
203 ENCODED_MESSAGE(MatchesEvent(
204 Eq("path/file.cc"), Eq(1234),
205 InMatchWindow(), Eq(logging::proto::FATAL),
206 Eq(absl::base_internal::GetTID()),
207 ElementsAre(EqualsProto(
208 R"pb(str: "WriteToStream: foo")pb")))))))
209 .WillOnce(DeathTestExpectedLogging());
210
211 test_sink.StartCapturingLogs();
212 WriteToStream(
213 "foo", &absl::LogDebugFatalStreamer("path/file.cc", 1234).stream());
214 },
215 DiedOfFatal, DeathTestValidateExpectations());
216 }
217 #endif
218
TEST(LogStreamerTest,LogStreamer)219 TEST(LogStreamerTest, LogStreamer) {
220 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
221
222 EXPECT_CALL(
223 test_sink,
224 Send(AllOf(
225 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
226 Prefix(IsTrue()), LogSeverity(Eq(absl::LogSeverity::kError)),
227 Timestamp(InMatchWindow()),
228 ThreadID(Eq(absl::base_internal::GetTID())),
229 TextMessage(Eq("WriteToStream: foo")),
230 ENCODED_MESSAGE(MatchesEvent(
231 Eq("path/file.cc"), Eq(1234), InMatchWindow(),
232 Eq(logging::proto::ERROR), Eq(absl::base_internal::GetTID()),
233 ElementsAre(EqualsProto(R"pb(str: "WriteToStream: foo")pb")))),
234 Stacktrace(IsEmpty()))));
235
236 test_sink.StartCapturingLogs();
237 WriteToStream(
238 "foo", &absl::LogStreamer(absl::LogSeverity::kError, "path/file.cc", 1234)
239 .stream());
240 }
241
242 #if GTEST_HAS_DEATH_TEST
TEST(LogStreamerDeathTest,LogStreamer)243 TEST(LogStreamerDeathTest, LogStreamer) {
244 EXPECT_EXIT(
245 {
246 absl::ScopedMockLog test_sink;
247
248 EXPECT_CALL(test_sink, Send)
249 .Times(AnyNumber())
250 .WillRepeatedly(DeathTestUnexpectedLogging());
251
252 EXPECT_CALL(test_sink,
253 Send(AllOf(SourceFilename(Eq("path/file.cc")),
254 SourceLine(Eq(1234)), Prefix(IsTrue()),
255 LogSeverity(Eq(absl::LogSeverity::kFatal)),
256 Timestamp(InMatchWindow()),
257 ThreadID(Eq(absl::base_internal::GetTID())),
258 TextMessage(Eq("WriteToStream: foo")),
259 ENCODED_MESSAGE(MatchesEvent(
260 Eq("path/file.cc"), Eq(1234),
261 InMatchWindow(), Eq(logging::proto::FATAL),
262 Eq(absl::base_internal::GetTID()),
263 ElementsAre(EqualsProto(
264 R"pb(str: "WriteToStream: foo")pb")))))))
265 .WillOnce(DeathTestExpectedLogging());
266
267 test_sink.StartCapturingLogs();
268 WriteToStream("foo", &absl::LogStreamer(absl::LogSeverity::kFatal,
269 "path/file.cc", 1234)
270 .stream());
271 },
272 DiedOfFatal, DeathTestValidateExpectations());
273 }
274 #endif
275
TEST(LogStreamerTest,PassedByReference)276 TEST(LogStreamerTest, PassedByReference) {
277 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
278
279 EXPECT_CALL(
280 test_sink,
281 Send(AllOf(
282 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
283 TextMessage(Eq("WriteToStreamRef: foo")),
284 ENCODED_MESSAGE(MatchesEvent(
285 Eq("path/file.cc"), Eq(1234), _, _, _,
286 ElementsAre(EqualsProto(R"pb(str: "WriteToStreamRef: foo")pb")))),
287 Stacktrace(IsEmpty()))));
288
289 test_sink.StartCapturingLogs();
290 WriteToStreamRef("foo", absl::LogInfoStreamer("path/file.cc", 1234).stream());
291 }
292
TEST(LogStreamerTest,StoredAsLocal)293 TEST(LogStreamerTest, StoredAsLocal) {
294 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
295
296 auto streamer = absl::LogInfoStreamer("path/file.cc", 1234);
297 WriteToStream("foo", &streamer.stream());
298 streamer.stream() << " ";
299 WriteToStreamRef("bar", streamer.stream());
300
301 // The call should happen when `streamer` goes out of scope; if it
302 // happened before this `EXPECT_CALL` the call would be unexpected and the
303 // test would fail.
304 EXPECT_CALL(
305 test_sink,
306 Send(AllOf(
307 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
308 TextMessage(Eq("WriteToStream: foo WriteToStreamRef: bar")),
309 ENCODED_MESSAGE(MatchesEvent(
310 Eq("path/file.cc"), Eq(1234), _, _, _,
311 ElementsAre(EqualsProto(
312 R"pb(str: "WriteToStream: foo WriteToStreamRef: bar")pb")))),
313 Stacktrace(IsEmpty()))));
314
315 test_sink.StartCapturingLogs();
316 }
317
318 #if GTEST_HAS_DEATH_TEST
TEST(LogStreamerDeathTest,StoredAsLocal)319 TEST(LogStreamerDeathTest, StoredAsLocal) {
320 EXPECT_EXIT(
321 {
322 // This is fatal when it goes out of scope, but not until then:
323 auto streamer = absl::LogFatalStreamer("path/file.cc", 1234);
324 std::cerr << "I'm still alive" << std::endl;
325 WriteToStream("foo", &streamer.stream());
326 },
327 DiedOfFatal, HasSubstr("I'm still alive"));
328 }
329 #endif
330
TEST(LogStreamerTest,LogsEmptyLine)331 TEST(LogStreamerTest, LogsEmptyLine) {
332 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
333
334 EXPECT_CALL(test_sink,
335 Send(AllOf(SourceFilename(Eq("path/file.cc")),
336 SourceLine(Eq(1234)), TextMessage(Eq("")),
337 ENCODED_MESSAGE(MatchesEvent(
338 Eq("path/file.cc"), Eq(1234), _, _, _,
339 ElementsAre(EqualsProto(R"pb(str: "")pb")))),
340 Stacktrace(IsEmpty()))));
341
342 test_sink.StartCapturingLogs();
343 absl::LogInfoStreamer("path/file.cc", 1234);
344 }
345
346 #if GTEST_HAS_DEATH_TEST
TEST(LogStreamerDeathTest,LogsEmptyLine)347 TEST(LogStreamerDeathTest, LogsEmptyLine) {
348 EXPECT_EXIT(
349 {
350 absl::ScopedMockLog test_sink;
351
352 EXPECT_CALL(test_sink, Log)
353 .Times(AnyNumber())
354 .WillRepeatedly(DeathTestUnexpectedLogging());
355
356 EXPECT_CALL(
357 test_sink,
358 Send(AllOf(SourceFilename(Eq("path/file.cc")), TextMessage(Eq("")),
359 ENCODED_MESSAGE(MatchesEvent(
360 Eq("path/file.cc"), _, _, _, _,
361 ElementsAre(EqualsProto(R"pb(str: "")pb")))))))
362 .WillOnce(DeathTestExpectedLogging());
363
364 test_sink.StartCapturingLogs();
365 // This is fatal even though it's never used:
366 auto streamer = absl::LogFatalStreamer("path/file.cc", 1234);
367 },
368 DiedOfFatal, DeathTestValidateExpectations());
369 }
370 #endif
371
TEST(LogStreamerTest,MoveConstruction)372 TEST(LogStreamerTest, MoveConstruction) {
373 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
374
375 EXPECT_CALL(
376 test_sink,
377 Send(AllOf(
378 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
379 LogSeverity(Eq(absl::LogSeverity::kInfo)),
380 TextMessage(Eq("hello 0x10 world 0x10")),
381 ENCODED_MESSAGE(MatchesEvent(
382 Eq("path/file.cc"), Eq(1234), _, Eq(logging::proto::INFO), _,
383 ElementsAre(EqualsProto(R"pb(str: "hello 0x10 world 0x10")pb")))),
384 Stacktrace(IsEmpty()))));
385
386 test_sink.StartCapturingLogs();
387 auto streamer1 = absl::LogInfoStreamer("path/file.cc", 1234);
388 streamer1.stream() << "hello " << std::hex << 16;
389 absl::LogStreamer streamer2(std::move(streamer1));
390 streamer2.stream() << " world " << 16;
391 }
392
TEST(LogStreamerTest,MoveAssignment)393 TEST(LogStreamerTest, MoveAssignment) {
394 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
395
396 testing::InSequence seq;
397 EXPECT_CALL(
398 test_sink,
399 Send(AllOf(
400 SourceFilename(Eq("path/file2.cc")), SourceLine(Eq(5678)),
401 LogSeverity(Eq(absl::LogSeverity::kWarning)),
402 TextMessage(Eq("something else")),
403 ENCODED_MESSAGE(MatchesEvent(
404 Eq("path/file2.cc"), Eq(5678), _, Eq(logging::proto::WARNING), _,
405 ElementsAre(EqualsProto(R"pb(str: "something else")pb")))),
406 Stacktrace(IsEmpty()))));
407 EXPECT_CALL(
408 test_sink,
409 Send(AllOf(
410 SourceFilename(Eq("path/file.cc")), SourceLine(Eq(1234)),
411 LogSeverity(Eq(absl::LogSeverity::kInfo)),
412 TextMessage(Eq("hello 0x10 world 0x10")),
413 ENCODED_MESSAGE(MatchesEvent(
414 Eq("path/file.cc"), Eq(1234), _, Eq(logging::proto::INFO), _,
415 ElementsAre(EqualsProto(R"pb(str: "hello 0x10 world 0x10")pb")))),
416 Stacktrace(IsEmpty()))));
417
418 test_sink.StartCapturingLogs();
419 auto streamer1 = absl::LogInfoStreamer("path/file.cc", 1234);
420 streamer1.stream() << "hello " << std::hex << 16;
421 auto streamer2 = absl::LogWarningStreamer("path/file2.cc", 5678);
422 streamer2.stream() << "something else";
423 streamer2 = std::move(streamer1);
424 streamer2.stream() << " world " << 16;
425 }
426
TEST(LogStreamerTest,CorrectDefaultFlags)427 TEST(LogStreamerTest, CorrectDefaultFlags) {
428 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
429
430 // The `boolalpha` and `showbase` flags should be set by default, to match
431 // `LOG`.
432 EXPECT_CALL(test_sink, Send(AllOf(TextMessage(Eq("false0xdeadbeef")))))
433 .Times(2);
434
435 test_sink.StartCapturingLogs();
436 absl::LogInfoStreamer("path/file.cc", 1234).stream()
437 << false << std::hex << 0xdeadbeef;
438 LOG(INFO) << false << std::hex << 0xdeadbeef;
439 }
440
441 } // namespace
442