1 /*
2 * Copyright (c) 2021-2025 Huawei Device Co., Ltd.
3 * Licensed under the Apache License, Version 2.0 (the "License");
4 * you may not use this file except in compliance with the License.
5 * You may obtain a copy of the License at
6 *
7 * http://www.apache.org/licenses/LICENSE-2.0
8 *
9 * Unless required by applicable law or agreed to in writing, software
10 * distributed under the License is distributed on an "AS IS" BASIS,
11 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 * See the License for the specific language governing permissions and
13 * limitations under the License.
14 */
15
16 #include "os/thread.h"
17 #include "utils/logger.h"
18 #include "utils/string_helpers.h"
19 #include "libpandabase/test_utilities.h"
20
21 #include <cstdio>
22
23 #include <fstream>
24 #include <regex>
25 #include <streambuf>
26
27 #include <gtest/gtest.h>
28
29 namespace ark::test {
30
31 // NOLINTBEGIN(cppcoreguidelines-pro-type-vararg)
32
DEATH_TEST(Logger,Initialization)33 DEATH_TEST(Logger, Initialization)
34 {
35 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
36
37 testing::FLAGS_gtest_death_test_style = "threadsafe";
38 testing::internal::CaptureStderr();
39
40 LOG(DEBUG, COMMON) << "1";
41 LOG(INFO, COMMON) << "2";
42 LOG(ERROR, COMMON) << "3";
43
44 std::string err = testing::internal::GetCapturedStderr();
45 EXPECT_EQ(err, "");
46
47 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, COMMON) << "4", "");
48
49 Logger::InitializeStdLogging(Logger::Level::DEBUG, ark::LOGGER_COMPONENT_MASK_ALL);
50 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
51
52 testing::internal::CaptureStderr();
53
54 LOG(DEBUG, COMMON) << "a";
55 LOG(INFO, COMMON) << "b";
56 LOG(ERROR, COMMON) << "c";
57
58 err = testing::internal::GetCapturedStderr();
59 uint32_t tid = os::thread::GetCurrentThreadId();
60 std::string res = helpers::string::Format(
61 #ifndef NDEBUG
62 "[TID %06x] D/common: a\n"
63 #endif
64 "[TID %06x] I/common: b\n"
65 "[TID %06x] E/common: c\n",
66 tid, tid, tid);
67 EXPECT_EQ(err, res);
68
69 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, COMMON) << "d", "\\[TID [0-9a-f]{6}\\] F/common: d");
70
71 Logger::Destroy();
72 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
73
74 testing::internal::CaptureStderr();
75
76 LOG(DEBUG, COMMON) << "1";
77 LOG(INFO, COMMON) << "2";
78 LOG(ERROR, COMMON) << "3";
79
80 err = testing::internal::GetCapturedStderr();
81 EXPECT_EQ(err, "");
82
83 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, COMMON) << "4", "");
84 }
85
DEATH_TEST(Logger,LoggingExceptionsFatal)86 DEATH_TEST(Logger, LoggingExceptionsFatal)
87 {
88 testing::FLAGS_gtest_death_test_style = "threadsafe";
89
90 ark::Logger::ComponentMask componentMask;
91 componentMask.set(Logger::Component::COMPILER);
92
93 Logger::InitializeStdLogging(Logger::Level::FATAL, componentMask);
94 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::COMPILER));
95 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ASSEMBLER));
96 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::DISASSEMBLER));
97 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::ERROR, Logger::Component::COMPILER));
98 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::ERROR, Logger::Component::ASSEMBLER));
99 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::ERROR, Logger::Component::DISASSEMBLER));
100
101 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, COMPILER) << "d1", "\\[TID [0-9a-f]{6}\\] F/compiler: d1");
102 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, ASSEMBLER) << "d2", "\\[TID [0-9a-f]{6}\\] F/assembler: d2");
103 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, DISASSEMBLER) << "d3", "\\[TID [0-9a-f]{6}\\] F/disassembler: d3");
104
105 testing::internal::CaptureStderr();
106
107 LOG(ERROR, COMPILER) << "c";
108 LOG(ERROR, ASSEMBLER) << "a";
109 LOG(ERROR, DISASSEMBLER) << "d";
110
111 std::string err = testing::internal::GetCapturedStderr();
112 EXPECT_EQ(err, "");
113
114 Logger::Destroy();
115 }
116
DEATH_TEST(Logger,LoggingExceptionsError)117 DEATH_TEST(Logger, LoggingExceptionsError)
118 {
119 testing::FLAGS_gtest_death_test_style = "threadsafe";
120
121 ark::Logger::ComponentMask componentMask;
122 componentMask.set(Logger::Component::COMPILER);
123
124 Logger::InitializeStdLogging(Logger::Level::ERROR, componentMask);
125 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::COMPILER));
126 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ASSEMBLER));
127 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::DISASSEMBLER));
128 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::ERROR, Logger::Component::COMPILER));
129 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::ERROR, Logger::Component::ASSEMBLER));
130 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::ERROR, Logger::Component::DISASSEMBLER));
131
132 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, COMPILER) << "d1", "\\[TID [0-9a-f]{6}\\] F/compiler: d1");
133 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, ASSEMBLER) << "d2", "\\[TID [0-9a-f]{6}\\] F/assembler: d2");
134 EXPECT_DEATH_IF_SUPPORTED(LOG(FATAL, DISASSEMBLER) << "d3", "\\[TID [0-9a-f]{6}\\] F/disassembler: d3");
135
136 testing::internal::CaptureStderr();
137
138 LOG(ERROR, COMPILER) << "c";
139 LOG(ERROR, ASSEMBLER) << "a";
140 LOG(ERROR, DISASSEMBLER) << "d";
141
142 std::string err = testing::internal::GetCapturedStderr();
143 uint32_t tid = os::thread::GetCurrentThreadId();
144 std::string res = helpers::string::Format("[TID %06x] E/compiler: c\n", tid);
145 EXPECT_EQ(err, res);
146
147 Logger::Destroy();
148 }
149
TEST(Logger,FilterInfo)150 TEST(Logger, FilterInfo)
151 {
152 Logger::InitializeStdLogging(Logger::Level::INFO, ark::LOGGER_COMPONENT_MASK_ALL);
153 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
154
155 testing::internal::CaptureStderr();
156
157 LOG(DEBUG, COMMON) << "a";
158 LOG(INFO, COMMON) << "b";
159 LOG(ERROR, COMMON) << "c";
160
161 std::string err = testing::internal::GetCapturedStderr();
162 uint32_t tid = os::thread::GetCurrentThreadId();
163 std::string res = helpers::string::Format(
164 "[TID %06x] I/common: b\n"
165 "[TID %06x] E/common: c\n",
166 tid, tid);
167 EXPECT_EQ(err, res);
168
169 Logger::Destroy();
170 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
171 }
172
TEST(Logger,FilterError)173 TEST(Logger, FilterError)
174 {
175 Logger::InitializeStdLogging(Logger::Level::ERROR, ark::LOGGER_COMPONENT_MASK_ALL);
176 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
177
178 testing::internal::CaptureStderr();
179
180 LOG(DEBUG, COMMON) << "a";
181 LOG(INFO, COMMON) << "b";
182 LOG(ERROR, COMMON) << "c";
183
184 std::string err = testing::internal::GetCapturedStderr();
185 uint32_t tid = os::thread::GetCurrentThreadId();
186 std::string res = helpers::string::Format("[TID %06x] E/common: c\n", tid);
187 EXPECT_EQ(err, res);
188
189 Logger::Destroy();
190 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
191 }
192
TEST(Logger,FilterFatal)193 TEST(Logger, FilterFatal)
194 {
195 Logger::InitializeStdLogging(Logger::Level::FATAL, ark::LOGGER_COMPONENT_MASK_ALL);
196 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
197
198 testing::internal::CaptureStderr();
199
200 LOG(DEBUG, COMMON) << "a";
201 LOG(INFO, COMMON) << "b";
202 LOG(ERROR, COMMON) << "c";
203
204 std::string err = testing::internal::GetCapturedStderr();
205 EXPECT_EQ(err, "");
206
207 Logger::Destroy();
208 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
209 }
210
TEST(Logger,ComponentFilter)211 TEST(Logger, ComponentFilter)
212 {
213 ark::Logger::ComponentMask componentMask;
214 componentMask.set(Logger::Component::COMPILER);
215 componentMask.set(Logger::Component::GC);
216
217 Logger::InitializeStdLogging(Logger::Level::INFO, componentMask);
218 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::WARNING, Logger::Component::ALLOC));
219 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::COMPILER));
220 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::GC));
221
222 testing::internal::CaptureStderr();
223
224 LOG(INFO, COMMON) << "a";
225 LOG(INFO, COMPILER) << "b";
226 LOG(INFO, RUNTIME) << "c";
227 LOG(INFO, GC) << "d";
228
229 std::string err = testing::internal::GetCapturedStderr();
230 uint32_t tid = os::thread::GetCurrentThreadId();
231 std::string res = helpers::string::Format(
232 "[TID %06x] I/compiler: b\n"
233 "[TID %06x] I/gc: d\n",
234 tid, tid);
235 EXPECT_EQ(err, res);
236
237 Logger::Destroy();
238 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
239 }
240
DEATH_TEST(Logger,FileLogging)241 DEATH_TEST(Logger, FileLogging)
242 {
243 uint32_t tid = os::thread::GetCurrentThreadId();
244 std::string logFilename = helpers::string::Format("/tmp/gtest_panda_logger_file_%06x", tid);
245
246 Logger::InitializeFileLogging(logFilename, Logger::Level::INFO,
247 ark::Logger::ComponentMask().set(Logger::Component::COMMON));
248 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
249 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::COMMON));
250
251 LOG(DEBUG, COMMON) << "a";
252 LOG(INFO, COMMON) << "b";
253 LOG(ERROR, COMPILER) << "c";
254 LOG(ERROR, COMMON) << "d";
255
256 #if GTEST_HAS_DEATH_TEST
257 testing::FLAGS_gtest_death_test_style = "fast";
258
259 EXPECT_DEATH(LOG(FATAL, COMMON) << "e", "");
260
261 std::string res = helpers::string::Format(
262 "\\[TID %06x\\] I/common: b\n"
263 "\\[TID %06x\\] E/common: d\n"
264 "\\[TID [0-9a-f]{6}\\] F/common: e\n",
265 tid, tid);
266 std::regex e(res);
267 {
268 std::ifstream logFileStream(logFilename);
269 std::string logFileContent((std::istreambuf_iterator<char>(logFileStream)), std::istreambuf_iterator<char>());
270 EXPECT_TRUE(std::regex_match(logFileContent, e));
271 }
272 #endif // GTEST_HAS_DEATH_TEST
273
274 EXPECT_EQ(std::remove(logFilename.c_str()), 0U);
275
276 Logger::Destroy();
277 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
278 }
279
TEST(Logger,Multiline)280 TEST(Logger, Multiline)
281 {
282 Logger::InitializeStdLogging(Logger::Level::INFO, ark::Logger::ComponentMask().set(Logger::Component::COMMON));
283 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
284 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::COMMON));
285
286 testing::internal::CaptureStderr();
287
288 LOG(INFO, COMMON) << "a\nb\nc\n\nd\n";
289
290 std::string err = testing::internal::GetCapturedStderr();
291 uint32_t tid = os::thread::GetCurrentThreadId();
292 std::string res = helpers::string::Format(
293 "[TID %06x] I/common: a\n"
294 "[TID %06x] I/common: b\n"
295 "[TID %06x] I/common: c\n"
296 "[TID %06x] I/common: \n"
297 "[TID %06x] I/common: d\n"
298 "[TID %06x] I/common: \n",
299 tid, tid, tid, tid, tid, tid);
300 EXPECT_EQ(err, res);
301
302 Logger::Destroy();
303 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
304 }
305
TEST(Logger,PLog)306 TEST(Logger, PLog)
307 {
308 Logger::InitializeStdLogging(Logger::Level::INFO, ark::LOGGER_COMPONENT_MASK_ALL);
309 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
310
311 testing::internal::CaptureStderr();
312
313 int errnum = errno;
314
315 errno = EEXIST;
316 PLOG(ERROR, COMMON) << "a";
317 errno = EACCES;
318 PLOG(INFO, COMPILER) << "b";
319 errno = errnum;
320
321 std::string err = testing::internal::GetCapturedStderr();
322 uint32_t tid = os::thread::GetCurrentThreadId();
323 std::string res = helpers::string::Format(
324 "[TID %06x] E/common: a: File exists\n"
325 "[TID %06x] I/compiler: b: Permission denied\n",
326 tid, tid, tid, tid);
327 EXPECT_EQ(err, res);
328
329 Logger::Destroy();
330 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
331 }
332
TEST(Logger,LogIf)333 TEST(Logger, LogIf)
334 {
335 Logger::InitializeStdLogging(Logger::Level::INFO, ark::LOGGER_COMPONENT_MASK_ALL);
336 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
337
338 testing::internal::CaptureStderr();
339
340 LOG_IF(true, INFO, COMMON) << "a";
341 LOG_IF(false, INFO, COMMON) << "b";
342
343 std::string err = testing::internal::GetCapturedStderr();
344 uint32_t tid = os::thread::GetCurrentThreadId();
345 std::string res = helpers::string::Format("[TID %06x] I/common: a\n", tid);
346 EXPECT_EQ(err, res);
347
348 Logger::Destroy();
349 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
350 }
351
TEST(Logger,LogOnce)352 TEST(Logger, LogOnce)
353 {
354 Logger::InitializeStdLogging(Logger::Level::INFO, ark::LOGGER_COMPONENT_MASK_ALL);
355 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
356
357 testing::internal::CaptureStderr();
358
359 LOG_ONCE(INFO, COMMON) << "a";
360 // NOLINTNEXTLINE(readability-magic-numbers)
361 for (size_t i = 0; i < 10U; ++i) {
362 LOG_ONCE(INFO, COMMON) << "b";
363 }
364 LOG_ONCE(INFO, COMMON) << "c";
365
366 std::string err = testing::internal::GetCapturedStderr();
367 uint32_t tid = os::thread::GetCurrentThreadId();
368 std::string res = helpers::string::Format(
369 "[TID %06x] I/common: a\n"
370 "[TID %06x] I/common: b\n"
371 "[TID %06x] I/common: c\n",
372 tid, tid, tid);
373 EXPECT_EQ(err, res);
374
375 Logger::Destroy();
376 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
377 }
378
TEST(Logger,LogDfx)379 TEST(Logger, LogDfx)
380 {
381 Logger::InitializeStdLogging(Logger::Level::ERROR, ark::LOGGER_COMPONENT_MASK_ALL);
382 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
383
384 DfxController::Initialize();
385 EXPECT_TRUE(DfxController::IsInitialized());
386 EXPECT_EQ(DfxController::GetOptionValue(DfxOptionHandler::DFXLOG), 0U);
387
388 testing::internal::CaptureStderr();
389
390 LOG_DFX(COMMON) << "a";
391 LOG_DFX(COMMON) << "b";
392 LOG_DFX(COMMON) << "c";
393
394 std::string err = testing::internal::GetCapturedStderr();
395 EXPECT_EQ(err, "");
396
397 DfxController::ResetOptionValueFromString("dfx-log:1");
398 EXPECT_EQ(DfxController::GetOptionValue(DfxOptionHandler::DFXLOG), 1U);
399
400 testing::internal::CaptureStderr();
401
402 LOG_DFX(COMMON) << "a";
403 LOG_DFX(COMMON) << "b";
404 LOG_DFX(COMMON) << "c";
405
406 err = testing::internal::GetCapturedStderr();
407 uint32_t tid = os::thread::GetCurrentThreadId();
408 std::string res = helpers::string::Format(
409 "[TID %06x] E/dfx: common log:a\n"
410 "[TID %06x] E/dfx: common log:b\n"
411 "[TID %06x] E/dfx: common log:c\n",
412 tid, tid, tid);
413 EXPECT_EQ(err, res);
414
415 Logger::Destroy();
416 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
417
418 DfxController::Destroy();
419 EXPECT_FALSE(DfxController::IsInitialized());
420 }
421
TEST(Logger,ProcessLogLevelFromString1)422 TEST(Logger, ProcessLogLevelFromString1)
423 {
424 Logger::InitializeStdLogging(Logger::Level::INFO, ark::LOGGER_COMPONENT_MASK_ALL);
425 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
426 testing::internal::CaptureStderr();
427 std::string s = "info";
428 Logger::ProcessLogLevelFromString(s);
429
430 std::string err = testing::internal::GetCapturedStderr();
431 std::string res = helpers::string::Format("");
432 EXPECT_EQ(err, res);
433 Logger::Destroy();
434 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
435 }
436
TEST(Logger,ProcessLogLevelFromString2)437 TEST(Logger, ProcessLogLevelFromString2)
438 {
439 Logger::InitializeStdLogging(Logger::Level::INFO, ark::LOGGER_COMPONENT_MASK_ALL);
440 EXPECT_TRUE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
441 testing::internal::CaptureStderr();
442
443 std::string s = "hello";
444 Logger::ProcessLogLevelFromString(s);
445 std::string err = testing::internal::GetCapturedStderr();
446 uint32_t tid = os::thread::GetCurrentThreadId();
447 std::string res = helpers::string::Format("[TID %06x] E/runtime: Unknown level hello\n", tid);
448 EXPECT_EQ(err, res);
449 Logger::Destroy();
450 EXPECT_FALSE(Logger::IsLoggingOn(Logger::Level::FATAL, Logger::Component::ALLOC));
451 }
452
453 // NOLINTEND(cppcoreguidelines-pro-type-vararg)
454
455 } // namespace ark::test
456