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 {
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.
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 
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 
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 {
69   void TearDown() override { Log::DisableAllLogChannels(); }
70 
71   static void SetUpTestCase() { Log::Register("chan", test_channel); }
72 
73   static void TearDownTestCase() {
74     Log::Unregister("chan");
75     llvm::llvm_shutdown();
76   }
77 };
78 
79 class TestLogHandler : public LogHandler {
80 public:
81   TestLogHandler() : m_messages(), m_stream(m_messages) {}
82 
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:
99   std::shared_ptr<LogHandler> getLogHandler() { return m_log_handler_sp; }
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 
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 
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 
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
134 LogChannelEnabledTest::logAndTakeOutput(llvm::StringRef Message) {
135   LLDB_LOG(m_log, "{0}", Message);
136   return takeOutput();
137 }
138 
139 TEST(LogTest, LLDB_LOG_nullptr) {
140   Log *log = nullptr;
141   LLDB_LOG(log, "{0}", 0); // Shouldn't crash
142 }
143 
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 
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;
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 
175 TEST(LogTest, CallbackLogHandler) {
176   CallbackLogHandler handler(TestCallback, &test_baton);
177   handler.Emit("Foobar");
178   EXPECT_EQ(1u, callback_count);
179 }
180 
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 
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 
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 
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 
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 
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 
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 
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 
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 
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