1 //===-- LogTest.cpp -------------------------------------------------------===//
2 //
3 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4 // See https://llvm.org/LICENSE.txt for license information.
5 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
6 //
7 //===----------------------------------------------------------------------===//
8
9 #include "gmock/gmock.h"
10 #include "gtest/gtest.h"
11
12 #include "lldb/Utility/Log.h"
13 #include "lldb/Utility/StreamString.h"
14 #include "llvm/ADT/BitmaskEnum.h"
15 #include "llvm/Support/ManagedStatic.h"
16 #include "llvm/Support/Threading.h"
17 #include <thread>
18
19 using namespace lldb;
20 using namespace lldb_private;
21
22 enum class TestChannel : Log::MaskType {
23 FOO = Log::ChannelFlag<0>,
24 BAR = Log::ChannelFlag<1>,
25 LLVM_MARK_AS_BITMASK_ENUM(BAR),
26 };
27
28 LLVM_ENABLE_BITMASK_ENUMS_IN_NAMESPACE();
29
30 static constexpr Log::Category test_categories[] = {
31 {{"foo"}, {"log foo"}, TestChannel::FOO},
32 {{"bar"}, {"log bar"}, TestChannel::BAR},
33 };
34
35 static Log::Channel test_channel(test_categories, TestChannel::FOO);
36
37 namespace lldb_private {
LogChannelFor()38 template <> Log::Channel &LogChannelFor<TestChannel>() { return test_channel; }
39 } // namespace lldb_private
40
41 // Wrap enable, disable and list functions to make them easier to test.
EnableChannel(std::shared_ptr<LogHandler> log_handler_sp,uint32_t log_options,llvm::StringRef channel,llvm::ArrayRef<const char * > categories,std::string & error)42 static bool EnableChannel(std::shared_ptr<LogHandler> log_handler_sp,
43 uint32_t log_options, llvm::StringRef channel,
44 llvm::ArrayRef<const char *> categories,
45 std::string &error) {
46 error.clear();
47 llvm::raw_string_ostream error_stream(error);
48 return Log::EnableLogChannel(log_handler_sp, log_options, channel, categories,
49 error_stream);
50 }
51
DisableChannel(llvm::StringRef channel,llvm::ArrayRef<const char * > categories,std::string & error)52 static bool DisableChannel(llvm::StringRef channel,
53 llvm::ArrayRef<const char *> categories,
54 std::string &error) {
55 error.clear();
56 llvm::raw_string_ostream error_stream(error);
57 return Log::DisableLogChannel(channel, categories, error_stream);
58 }
59
ListCategories(llvm::StringRef channel,std::string & result)60 static bool ListCategories(llvm::StringRef channel, std::string &result) {
61 result.clear();
62 llvm::raw_string_ostream result_stream(result);
63 return Log::ListChannelCategories(channel, result_stream);
64 }
65
66 namespace {
67 // A test fixture which provides tests with a pre-registered channel.
68 struct LogChannelTest : public ::testing::Test {
TearDown__anon983438870111::LogChannelTest69 void TearDown() override { Log::DisableAllLogChannels(); }
70
SetUpTestCase__anon983438870111::LogChannelTest71 static void SetUpTestCase() { Log::Register("chan", test_channel); }
72
TearDownTestCase__anon983438870111::LogChannelTest73 static void TearDownTestCase() {
74 Log::Unregister("chan");
75 llvm::llvm_shutdown();
76 }
77 };
78
79 class TestLogHandler : public LogHandler {
80 public:
TestLogHandler()81 TestLogHandler() : m_messages(), m_stream(m_messages) {}
82
Emit(llvm::StringRef message)83 void Emit(llvm::StringRef message) override { m_stream << message; }
84
85 llvm::SmallString<0> m_messages;
86 llvm::raw_svector_ostream m_stream;
87 };
88
89 // A test fixture which provides tests with a pre-registered and pre-enabled
90 // channel. Additionally, the messages written to that channel are captured and
91 // made available via getMessage().
92 class LogChannelEnabledTest : public LogChannelTest {
93 std::shared_ptr<TestLogHandler> m_log_handler_sp =
94 std::make_shared<TestLogHandler>();
95 Log *m_log;
96 size_t m_consumed_bytes = 0;
97
98 protected:
getLogHandler()99 std::shared_ptr<LogHandler> getLogHandler() { return m_log_handler_sp; }
getLog()100 Log *getLog() { return m_log; }
101 llvm::StringRef takeOutput();
102 llvm::StringRef logAndTakeOutput(llvm::StringRef Message);
103 llvm::StringRef logAndTakeOutputf(llvm::StringRef Message);
104
105 public:
106 void SetUp() override;
107 };
108
GetDumpAsString(const RotatingLogHandler & handler)109 static std::string GetDumpAsString(const RotatingLogHandler &handler) {
110 std::string buffer;
111 llvm::raw_string_ostream stream(buffer);
112 handler.Dump(stream);
113 return buffer;
114 }
115 } // end anonymous namespace
116
SetUp()117 void LogChannelEnabledTest::SetUp() {
118 LogChannelTest::SetUp();
119
120 std::string error;
121 ASSERT_TRUE(EnableChannel(m_log_handler_sp, 0, "chan", {}, error));
122
123 m_log = GetLog(TestChannel::FOO);
124 ASSERT_NE(nullptr, m_log);
125 }
126
takeOutput()127 llvm::StringRef LogChannelEnabledTest::takeOutput() {
128 llvm::StringRef result =
129 m_log_handler_sp->m_stream.str().drop_front(m_consumed_bytes);
130 m_consumed_bytes += result.size();
131 return result;
132 }
133
134 llvm::StringRef
logAndTakeOutput(llvm::StringRef Message)135 LogChannelEnabledTest::logAndTakeOutput(llvm::StringRef Message) {
136 LLDB_LOG(m_log, "{0}", Message);
137 return takeOutput();
138 }
139
140 llvm::StringRef
logAndTakeOutputf(llvm::StringRef Message)141 LogChannelEnabledTest::logAndTakeOutputf(llvm::StringRef Message) {
142 LLDB_LOGF(m_log, "%s", Message.str().c_str());
143 return takeOutput();
144 }
145
TEST(LogTest,LLDB_LOG_nullptr)146 TEST(LogTest, LLDB_LOG_nullptr) {
147 Log *log = nullptr;
148 LLDB_LOG(log, "{0}", 0); // Shouldn't crash
149 }
150
TEST(LogTest,Register)151 TEST(LogTest, Register) {
152 llvm::llvm_shutdown_obj obj;
153 Log::Register("chan", test_channel);
154 Log::Unregister("chan");
155 Log::Register("chan", test_channel);
156 Log::Unregister("chan");
157 }
158
TEST(LogTest,Unregister)159 TEST(LogTest, Unregister) {
160 llvm::llvm_shutdown_obj obj;
161 Log::Register("chan", test_channel);
162 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
163 std::string message;
164 auto log_handler_sp = std::make_shared<TestLogHandler>();
165 EXPECT_TRUE(
166 Log::EnableLogChannel(log_handler_sp, 0, "chan", {"foo"}, llvm::nulls()));
167 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
168 Log::Unregister("chan");
169 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
170 }
171
172 namespace {
173 static char test_baton;
174 static size_t callback_count = 0;
TestCallback(const char * data,void * baton)175 static void TestCallback(const char *data, void *baton) {
176 EXPECT_STREQ("Foobar", data);
177 EXPECT_EQ(&test_baton, baton);
178 ++callback_count;
179 }
180 } // namespace
181
TEST(LogTest,CallbackLogHandler)182 TEST(LogTest, CallbackLogHandler) {
183 CallbackLogHandler handler(TestCallback, &test_baton);
184 handler.Emit("Foobar");
185 EXPECT_EQ(1u, callback_count);
186 }
187
TEST(LogHandlerTest,RotatingLogHandler)188 TEST(LogHandlerTest, RotatingLogHandler) {
189 RotatingLogHandler handler(3);
190
191 handler.Emit("foo");
192 handler.Emit("bar");
193 EXPECT_EQ(GetDumpAsString(handler), "foobar");
194
195 handler.Emit("baz");
196 handler.Emit("qux");
197 EXPECT_EQ(GetDumpAsString(handler), "barbazqux");
198
199 handler.Emit("quux");
200 EXPECT_EQ(GetDumpAsString(handler), "bazquxquux");
201 }
202
TEST(LogHandlerTest,TeeLogHandler)203 TEST(LogHandlerTest, TeeLogHandler) {
204 auto handler1 = std::make_shared<RotatingLogHandler>(2);
205 auto handler2 = std::make_shared<RotatingLogHandler>(2);
206 TeeLogHandler handler(handler1, handler2);
207
208 handler.Emit("foo");
209 handler.Emit("bar");
210
211 EXPECT_EQ(GetDumpAsString(*handler1), "foobar");
212 EXPECT_EQ(GetDumpAsString(*handler2), "foobar");
213 }
214
TEST_F(LogChannelTest,Enable)215 TEST_F(LogChannelTest, Enable) {
216 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
217 std::string message;
218 auto log_handler_sp = std::make_shared<TestLogHandler>();
219 std::string error;
220 ASSERT_FALSE(EnableChannel(log_handler_sp, 0, "chanchan", {}, error));
221 EXPECT_EQ("Invalid log channel 'chanchan'.\n", error);
222
223 EXPECT_TRUE(EnableChannel(log_handler_sp, 0, "chan", {}, error));
224 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
225 EXPECT_EQ(nullptr, GetLog(TestChannel::BAR));
226 EXPECT_NE(nullptr, GetLog(TestChannel::FOO | TestChannel::BAR));
227
228 EXPECT_TRUE(EnableChannel(log_handler_sp, 0, "chan", {"bar"}, error));
229 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
230 EXPECT_NE(nullptr, GetLog(TestChannel::BAR));
231
232 EXPECT_TRUE(EnableChannel(log_handler_sp, 0, "chan", {"baz"}, error));
233 EXPECT_NE(std::string::npos, error.find("unrecognized log category 'baz'"))
234 << "error: " << error;
235 }
236
TEST_F(LogChannelTest,EnableOptions)237 TEST_F(LogChannelTest, EnableOptions) {
238 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
239 std::string message;
240 auto log_handler_sp = std::make_shared<TestLogHandler>();
241 std::string error;
242 EXPECT_TRUE(EnableChannel(log_handler_sp, LLDB_LOG_OPTION_VERBOSE, "chan", {},
243 error));
244
245 Log *log = GetLog(TestChannel::FOO);
246 ASSERT_NE(nullptr, log);
247 EXPECT_TRUE(log->GetVerbose());
248 }
249
TEST_F(LogChannelTest,Disable)250 TEST_F(LogChannelTest, Disable) {
251 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
252 std::string message;
253 auto log_handler_sp = std::make_shared<TestLogHandler>();
254 std::string error;
255 EXPECT_TRUE(EnableChannel(log_handler_sp, 0, "chan", {"foo", "bar"}, error));
256 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
257 EXPECT_NE(nullptr, GetLog(TestChannel::BAR));
258
259 EXPECT_TRUE(DisableChannel("chan", {"bar"}, error));
260 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
261 EXPECT_EQ(nullptr, GetLog(TestChannel::BAR));
262
263 EXPECT_TRUE(DisableChannel("chan", {"baz"}, error));
264 EXPECT_NE(std::string::npos, error.find("unrecognized log category 'baz'"))
265 << "error: " << error;
266 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
267 EXPECT_EQ(nullptr, GetLog(TestChannel::BAR));
268
269 EXPECT_TRUE(DisableChannel("chan", {}, error));
270 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO | TestChannel::BAR));
271 }
272
TEST_F(LogChannelTest,List)273 TEST_F(LogChannelTest, List) {
274 std::string list;
275 EXPECT_TRUE(ListCategories("chan", list));
276 std::string expected =
277 R"(Logging categories for 'chan':
278 all - all available logging categories
279 default - default set of logging categories
280 foo - log foo
281 bar - log bar
282 )";
283 EXPECT_EQ(expected, list);
284
285 EXPECT_FALSE(ListCategories("chanchan", list));
286 EXPECT_EQ("Invalid log channel 'chanchan'.\n", list);
287 }
288
TEST_F(LogChannelEnabledTest,log_options)289 TEST_F(LogChannelEnabledTest, log_options) {
290 std::string Err;
291 EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
292 EXPECT_TRUE(EnableChannel(getLogHandler(), 0, "chan", {}, Err));
293 EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
294
295 {
296 EXPECT_TRUE(EnableChannel(getLogHandler(), LLDB_LOG_OPTION_PREPEND_SEQUENCE,
297 "chan", {}, Err));
298 llvm::StringRef Msg = logAndTakeOutput("Hello World");
299 int seq_no;
300 EXPECT_EQ(1, sscanf(Msg.str().c_str(), "%d Hello World", &seq_no));
301 }
302
303 {
304 EXPECT_TRUE(EnableChannel(getLogHandler(),
305 LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION, "chan", {},
306 Err));
307 llvm::StringRef Msg = logAndTakeOutput("Hello World");
308 char File[12];
309 char Function[17];
310
311 sscanf(Msg.str().c_str(),
312 "%[^:]:%s Hello World", File,
313 Function);
314 EXPECT_STRCASEEQ("LogTest.cpp", File);
315 EXPECT_STREQ("logAndTakeOutput", Function);
316 }
317
318 {
319 EXPECT_TRUE(EnableChannel(getLogHandler(),
320 LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION, "chan", {},
321 Err));
322 llvm::StringRef Msg = logAndTakeOutputf("Hello World");
323 char File[12];
324 char Function[18];
325
326 sscanf(Msg.str().c_str(),
327 "%[^:]:%s Hello World", File,
328 Function);
329 EXPECT_STRCASEEQ("LogTest.cpp", File);
330 EXPECT_STREQ("logAndTakeOutputf", Function);
331 }
332
333 EXPECT_TRUE(EnableChannel(getLogHandler(),
334 LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD, "chan", {},
335 Err));
336 EXPECT_EQ(llvm::formatv("[{0,0+4}/{1,0+4}] Hello World\n", ::getpid(),
337 llvm::get_threadid())
338 .str(),
339 logAndTakeOutput("Hello World"));
340 }
341
TEST_F(LogChannelEnabledTest,LLDB_LOG_ERROR)342 TEST_F(LogChannelEnabledTest, LLDB_LOG_ERROR) {
343 LLDB_LOG_ERROR(getLog(), llvm::Error::success(), "Foo failed: {0}");
344 ASSERT_EQ("", takeOutput());
345
346 LLDB_LOG_ERROR(getLog(),
347 llvm::make_error<llvm::StringError>(
348 "My Error", llvm::inconvertibleErrorCode()),
349 "Foo failed: {0}");
350 ASSERT_EQ("Foo failed: My Error\n", takeOutput());
351
352 // Doesn't log, but doesn't assert either
353 LLDB_LOG_ERROR(nullptr,
354 llvm::make_error<llvm::StringError>(
355 "My Error", llvm::inconvertibleErrorCode()),
356 "Foo failed: {0}");
357 }
358
TEST_F(LogChannelEnabledTest,LogThread)359 TEST_F(LogChannelEnabledTest, LogThread) {
360 // Test that we are able to concurrently write to a log channel and disable
361 // it.
362 std::string err;
363
364 // Start logging on one thread. Concurrently, try disabling the log channel.
365 std::thread log_thread([this] { LLDB_LOG(getLog(), "Hello World"); });
366 EXPECT_TRUE(DisableChannel("chan", {}, err));
367 log_thread.join();
368
369 // The log thread either managed to write to the log in time, or it didn't. In
370 // either case, we should not trip any undefined behavior (run the test under
371 // TSAN to verify this).
372 EXPECT_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));
373 }
374
TEST_F(LogChannelEnabledTest,LogVerboseThread)375 TEST_F(LogChannelEnabledTest, LogVerboseThread) {
376 // Test that we are able to concurrently check the verbose flag of a log
377 // channel and enable it.
378 std::string err;
379
380 // Start logging on one thread. Concurrently, try enabling the log channel
381 // (with different log options).
382 std::thread log_thread([this] { LLDB_LOGV(getLog(), "Hello World"); });
383 EXPECT_TRUE(
384 EnableChannel(getLogHandler(), LLDB_LOG_OPTION_VERBOSE, "chan", {}, err));
385 log_thread.join();
386
387 // The log thread either managed to write to the log, or it didn't. In either
388 // case, we should not trip any undefined behavior (run the test under TSAN to
389 // verify this).
390 EXPECT_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));
391 }
392
TEST_F(LogChannelEnabledTest,LogGetLogThread)393 TEST_F(LogChannelEnabledTest, LogGetLogThread) {
394 // Test that we are able to concurrently get mask of a Log object and disable
395 // it.
396 std::string err;
397
398 // Try fetching the log mask on one thread. Concurrently, try disabling the
399 // log channel.
400 uint64_t mask;
401 std::thread log_thread([this, &mask] { mask = getLog()->GetMask(); });
402 EXPECT_TRUE(DisableChannel("chan", {}, err));
403 log_thread.join();
404
405 // The mask should be either zero of "FOO". In either case, we should not trip
406 // any undefined behavior (run the test under TSAN to verify this).
407 EXPECT_THAT(mask, testing::AnyOf(0, Log::MaskType(TestChannel::FOO)));
408 }
409