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__anon274957a40111::LogChannelTest69 void TearDown() override { Log::DisableAllLogChannels(); }
70
SetUpTestCase__anon274957a40111::LogChannelTest71 static void SetUpTestCase() { Log::Register("chan", test_channel); }
72
TearDownTestCase__anon274957a40111::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
104 public:
105 void SetUp() override;
106 };
107
GetDumpAsString(const RotatingLogHandler & handler)108 static std::string GetDumpAsString(const RotatingLogHandler &handler) {
109 std::string buffer;
110 llvm::raw_string_ostream stream(buffer);
111 handler.Dump(stream);
112 return buffer;
113 }
114 } // end anonymous namespace
115
SetUp()116 void LogChannelEnabledTest::SetUp() {
117 LogChannelTest::SetUp();
118
119 std::string error;
120 ASSERT_TRUE(EnableChannel(m_log_handler_sp, 0, "chan", {}, error));
121
122 m_log = GetLog(TestChannel::FOO);
123 ASSERT_NE(nullptr, m_log);
124 }
125
takeOutput()126 llvm::StringRef LogChannelEnabledTest::takeOutput() {
127 llvm::StringRef result =
128 m_log_handler_sp->m_stream.str().drop_front(m_consumed_bytes);
129 m_consumed_bytes += result.size();
130 return result;
131 }
132
133 llvm::StringRef
logAndTakeOutput(llvm::StringRef Message)134 LogChannelEnabledTest::logAndTakeOutput(llvm::StringRef Message) {
135 LLDB_LOG(m_log, "{0}", Message);
136 return takeOutput();
137 }
138
TEST(LogTest,LLDB_LOG_nullptr)139 TEST(LogTest, LLDB_LOG_nullptr) {
140 Log *log = nullptr;
141 LLDB_LOG(log, "{0}", 0); // Shouldn't crash
142 }
143
TEST(LogTest,Register)144 TEST(LogTest, Register) {
145 llvm::llvm_shutdown_obj obj;
146 Log::Register("chan", test_channel);
147 Log::Unregister("chan");
148 Log::Register("chan", test_channel);
149 Log::Unregister("chan");
150 }
151
TEST(LogTest,Unregister)152 TEST(LogTest, Unregister) {
153 llvm::llvm_shutdown_obj obj;
154 Log::Register("chan", test_channel);
155 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
156 std::string message;
157 auto log_handler_sp = std::make_shared<TestLogHandler>();
158 EXPECT_TRUE(
159 Log::EnableLogChannel(log_handler_sp, 0, "chan", {"foo"}, llvm::nulls()));
160 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
161 Log::Unregister("chan");
162 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
163 }
164
165 namespace {
166 static char test_baton;
167 static size_t callback_count = 0;
TestCallback(const char * data,void * baton)168 static void TestCallback(const char *data, void *baton) {
169 EXPECT_STREQ("Foobar", data);
170 EXPECT_EQ(&test_baton, baton);
171 ++callback_count;
172 }
173 } // namespace
174
TEST(LogTest,CallbackLogHandler)175 TEST(LogTest, CallbackLogHandler) {
176 CallbackLogHandler handler(TestCallback, &test_baton);
177 handler.Emit("Foobar");
178 EXPECT_EQ(1u, callback_count);
179 }
180
TEST(LogHandlerTest,RotatingLogHandler)181 TEST(LogHandlerTest, RotatingLogHandler) {
182 RotatingLogHandler handler(3);
183
184 handler.Emit("foo");
185 handler.Emit("bar");
186 EXPECT_EQ(GetDumpAsString(handler), "foobar");
187
188 handler.Emit("baz");
189 handler.Emit("qux");
190 EXPECT_EQ(GetDumpAsString(handler), "barbazqux");
191
192 handler.Emit("quux");
193 EXPECT_EQ(GetDumpAsString(handler), "bazquxquux");
194 }
195
TEST_F(LogChannelTest,Enable)196 TEST_F(LogChannelTest, Enable) {
197 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
198 std::string message;
199 auto log_handler_sp = std::make_shared<TestLogHandler>();
200 std::string error;
201 ASSERT_FALSE(EnableChannel(log_handler_sp, 0, "chanchan", {}, error));
202 EXPECT_EQ("Invalid log channel 'chanchan'.\n", error);
203
204 EXPECT_TRUE(EnableChannel(log_handler_sp, 0, "chan", {}, error));
205 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
206 EXPECT_EQ(nullptr, GetLog(TestChannel::BAR));
207 EXPECT_NE(nullptr, GetLog(TestChannel::FOO | TestChannel::BAR));
208
209 EXPECT_TRUE(EnableChannel(log_handler_sp, 0, "chan", {"bar"}, error));
210 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
211 EXPECT_NE(nullptr, GetLog(TestChannel::BAR));
212
213 EXPECT_TRUE(EnableChannel(log_handler_sp, 0, "chan", {"baz"}, error));
214 EXPECT_NE(std::string::npos, error.find("unrecognized log category 'baz'"))
215 << "error: " << error;
216 }
217
TEST_F(LogChannelTest,EnableOptions)218 TEST_F(LogChannelTest, EnableOptions) {
219 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
220 std::string message;
221 auto log_handler_sp = std::make_shared<TestLogHandler>();
222 std::string error;
223 EXPECT_TRUE(EnableChannel(log_handler_sp, LLDB_LOG_OPTION_VERBOSE, "chan", {},
224 error));
225
226 Log *log = GetLog(TestChannel::FOO);
227 ASSERT_NE(nullptr, log);
228 EXPECT_TRUE(log->GetVerbose());
229 }
230
TEST_F(LogChannelTest,Disable)231 TEST_F(LogChannelTest, Disable) {
232 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
233 std::string message;
234 auto log_handler_sp = std::make_shared<TestLogHandler>();
235 std::string error;
236 EXPECT_TRUE(EnableChannel(log_handler_sp, 0, "chan", {"foo", "bar"}, error));
237 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
238 EXPECT_NE(nullptr, GetLog(TestChannel::BAR));
239
240 EXPECT_TRUE(DisableChannel("chan", {"bar"}, error));
241 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
242 EXPECT_EQ(nullptr, GetLog(TestChannel::BAR));
243
244 EXPECT_TRUE(DisableChannel("chan", {"baz"}, error));
245 EXPECT_NE(std::string::npos, error.find("unrecognized log category 'baz'"))
246 << "error: " << error;
247 EXPECT_NE(nullptr, GetLog(TestChannel::FOO));
248 EXPECT_EQ(nullptr, GetLog(TestChannel::BAR));
249
250 EXPECT_TRUE(DisableChannel("chan", {}, error));
251 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO | TestChannel::BAR));
252 }
253
TEST_F(LogChannelTest,List)254 TEST_F(LogChannelTest, List) {
255 std::string list;
256 EXPECT_TRUE(ListCategories("chan", list));
257 std::string expected =
258 R"(Logging categories for 'chan':
259 all - all available logging categories
260 default - default set of logging categories
261 foo - log foo
262 bar - log bar
263 )";
264 EXPECT_EQ(expected, list);
265
266 EXPECT_FALSE(ListCategories("chanchan", list));
267 EXPECT_EQ("Invalid log channel 'chanchan'.\n", list);
268 }
269
TEST_F(LogChannelEnabledTest,log_options)270 TEST_F(LogChannelEnabledTest, log_options) {
271 std::string Err;
272 EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
273 EXPECT_TRUE(EnableChannel(getLogHandler(), 0, "chan", {}, Err));
274 EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
275
276 {
277 EXPECT_TRUE(EnableChannel(getLogHandler(), LLDB_LOG_OPTION_PREPEND_SEQUENCE,
278 "chan", {}, Err));
279 llvm::StringRef Msg = logAndTakeOutput("Hello World");
280 int seq_no;
281 EXPECT_EQ(1, sscanf(Msg.str().c_str(), "%d Hello World", &seq_no));
282 }
283
284 {
285 EXPECT_TRUE(EnableChannel(getLogHandler(),
286 LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION, "chan", {},
287 Err));
288 llvm::StringRef Msg = logAndTakeOutput("Hello World");
289 char File[12];
290 char Function[17];
291
292 sscanf(Msg.str().c_str(),
293 "%[^:]:%s Hello World", File,
294 Function);
295 EXPECT_STRCASEEQ("LogTest.cpp", File);
296 EXPECT_STREQ("logAndTakeOutput", Function);
297 }
298
299 EXPECT_TRUE(EnableChannel(getLogHandler(),
300 LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD, "chan", {},
301 Err));
302 EXPECT_EQ(llvm::formatv("[{0,0+4}/{1,0+4}] Hello World\n", ::getpid(),
303 llvm::get_threadid())
304 .str(),
305 logAndTakeOutput("Hello World"));
306 }
307
TEST_F(LogChannelEnabledTest,LLDB_LOG_ERROR)308 TEST_F(LogChannelEnabledTest, LLDB_LOG_ERROR) {
309 LLDB_LOG_ERROR(getLog(), llvm::Error::success(), "Foo failed: {0}");
310 ASSERT_EQ("", takeOutput());
311
312 LLDB_LOG_ERROR(getLog(),
313 llvm::make_error<llvm::StringError>(
314 "My Error", llvm::inconvertibleErrorCode()),
315 "Foo failed: {0}");
316 ASSERT_EQ("Foo failed: My Error\n", takeOutput());
317
318 // Doesn't log, but doesn't assert either
319 LLDB_LOG_ERROR(nullptr,
320 llvm::make_error<llvm::StringError>(
321 "My Error", llvm::inconvertibleErrorCode()),
322 "Foo failed: {0}");
323 }
324
TEST_F(LogChannelEnabledTest,LogThread)325 TEST_F(LogChannelEnabledTest, LogThread) {
326 // Test that we are able to concurrently write to a log channel and disable
327 // it.
328 std::string err;
329
330 // Start logging on one thread. Concurrently, try disabling the log channel.
331 std::thread log_thread([this] { LLDB_LOG(getLog(), "Hello World"); });
332 EXPECT_TRUE(DisableChannel("chan", {}, err));
333 log_thread.join();
334
335 // The log thread either managed to write to the log in time, or it didn't. In
336 // either case, we should not trip any undefined behavior (run the test under
337 // TSAN to verify this).
338 EXPECT_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));
339 }
340
TEST_F(LogChannelEnabledTest,LogVerboseThread)341 TEST_F(LogChannelEnabledTest, LogVerboseThread) {
342 // Test that we are able to concurrently check the verbose flag of a log
343 // channel and enable it.
344 std::string err;
345
346 // Start logging on one thread. Concurrently, try enabling the log channel
347 // (with different log options).
348 std::thread log_thread([this] { LLDB_LOGV(getLog(), "Hello World"); });
349 EXPECT_TRUE(
350 EnableChannel(getLogHandler(), LLDB_LOG_OPTION_VERBOSE, "chan", {}, err));
351 log_thread.join();
352
353 // The log thread either managed to write to the log, or it didn't. In either
354 // case, we should not trip any undefined behavior (run the test under TSAN to
355 // verify this).
356 EXPECT_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));
357 }
358
TEST_F(LogChannelEnabledTest,LogGetLogThread)359 TEST_F(LogChannelEnabledTest, LogGetLogThread) {
360 // Test that we are able to concurrently get mask of a Log object and disable
361 // it.
362 std::string err;
363
364 // Try fetching the log mask on one thread. Concurrently, try disabling the
365 // log channel.
366 uint32_t mask;
367 std::thread log_thread([this, &mask] { mask = getLog()->GetMask().Get(); });
368 EXPECT_TRUE(DisableChannel("chan", {}, err));
369 log_thread.join();
370
371 // The mask should be either zero of "FOO". In either case, we should not trip
372 // any undefined behavior (run the test under TSAN to verify this).
373 EXPECT_THAT(mask, testing::AnyOf(0, Log::MaskType(TestChannel::FOO)));
374 }
375