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/Support/ManagedStatic.h"
15 #include "llvm/Support/Threading.h"
16 #include <thread>
17 
18 using namespace lldb;
19 using namespace lldb_private;
20 
21 enum { FOO = 1, BAR = 2 };
22 static constexpr Log::Category test_categories[] = {
23     {{"foo"}, {"log foo"}, FOO}, {{"bar"}, {"log bar"}, BAR},
24 };
25 static constexpr uint32_t default_flags = FOO;
26 
27 static Log::Channel test_channel(test_categories, default_flags);
28 
29 // Wrap enable, disable and list functions to make them easier to test.
30 static bool EnableChannel(std::shared_ptr<llvm::raw_ostream> stream_sp,
31                           uint32_t log_options, llvm::StringRef channel,
32                           llvm::ArrayRef<const char *> categories,
33                           std::string &error) {
34   error.clear();
35   llvm::raw_string_ostream error_stream(error);
36   return Log::EnableLogChannel(stream_sp, log_options, channel, categories,
37                                error_stream);
38 }
39 
40 static bool DisableChannel(llvm::StringRef channel,
41                            llvm::ArrayRef<const char *> categories,
42                            std::string &error) {
43   error.clear();
44   llvm::raw_string_ostream error_stream(error);
45   return Log::DisableLogChannel(channel, categories, error_stream);
46 }
47 
48 static bool ListCategories(llvm::StringRef channel, std::string &result) {
49   result.clear();
50   llvm::raw_string_ostream result_stream(result);
51   return Log::ListChannelCategories(channel, result_stream);
52 }
53 
54 namespace {
55 // A test fixture which provides tests with a pre-registered channel.
56 struct LogChannelTest : public ::testing::Test {
57   void TearDown() override { Log::DisableAllLogChannels(); }
58 
59   static void SetUpTestCase() {
60     Log::Register("chan", test_channel);
61   }
62 
63   static void TearDownTestCase() {
64     Log::Unregister("chan");
65     llvm::llvm_shutdown();
66   }
67 };
68 
69 // A test fixture which provides tests with a pre-registered and pre-enabled
70 // channel. Additionally, the messages written to that channel are captured and
71 // made available via getMessage().
72 class LogChannelEnabledTest : public LogChannelTest {
73   llvm::SmallString<0> m_messages;
74   std::shared_ptr<llvm::raw_svector_ostream> m_stream_sp =
75       std::make_shared<llvm::raw_svector_ostream>(m_messages);
76   Log *m_log;
77   size_t m_consumed_bytes = 0;
78 
79 protected:
80   std::shared_ptr<llvm::raw_ostream> getStream() { return m_stream_sp; }
81   Log *getLog() { return m_log; }
82   llvm::StringRef takeOutput();
83   llvm::StringRef logAndTakeOutput(llvm::StringRef Message);
84 
85 public:
86   void SetUp() override;
87 };
88 } // end anonymous namespace
89 
90 void LogChannelEnabledTest::SetUp() {
91   LogChannelTest::SetUp();
92 
93   std::string error;
94   ASSERT_TRUE(EnableChannel(m_stream_sp, 0, "chan", {}, error));
95 
96   m_log = test_channel.GetLogIfAll(FOO);
97   ASSERT_NE(nullptr, m_log);
98 }
99 
100 llvm::StringRef LogChannelEnabledTest::takeOutput() {
101   llvm::StringRef result = m_stream_sp->str().drop_front(m_consumed_bytes);
102   m_consumed_bytes+= result.size();
103   return result;
104 }
105 
106 llvm::StringRef LogChannelEnabledTest::logAndTakeOutput(llvm::StringRef Message) {
107   LLDB_LOG(m_log, "{0}", Message);
108   return takeOutput();
109 }
110 
111 TEST(LogTest, LLDB_LOG_nullptr) {
112   Log *log = nullptr;
113   LLDB_LOG(log, "{0}", 0); // Shouldn't crash
114 }
115 
116 TEST(LogTest, Register) {
117   llvm::llvm_shutdown_obj obj;
118   Log::Register("chan", test_channel);
119   Log::Unregister("chan");
120   Log::Register("chan", test_channel);
121   Log::Unregister("chan");
122 }
123 
124 TEST(LogTest, Unregister) {
125   llvm::llvm_shutdown_obj obj;
126   Log::Register("chan", test_channel);
127   EXPECT_EQ(nullptr, test_channel.GetLogIfAny(FOO));
128   std::string message;
129   std::shared_ptr<llvm::raw_string_ostream> stream_sp(
130       new llvm::raw_string_ostream(message));
131   EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", {"foo"}, llvm::nulls()));
132   EXPECT_NE(nullptr, test_channel.GetLogIfAny(FOO));
133   Log::Unregister("chan");
134   EXPECT_EQ(nullptr, test_channel.GetLogIfAny(FOO));
135 }
136 
137 TEST_F(LogChannelTest, Enable) {
138   EXPECT_EQ(nullptr, test_channel.GetLogIfAll(FOO));
139   std::string message;
140   std::shared_ptr<llvm::raw_string_ostream> stream_sp(
141       new llvm::raw_string_ostream(message));
142   std::string error;
143   ASSERT_FALSE(EnableChannel(stream_sp, 0, "chanchan", {}, error));
144   EXPECT_EQ("Invalid log channel 'chanchan'.\n", error);
145 
146   EXPECT_TRUE(EnableChannel(stream_sp, 0, "chan", {}, error));
147   EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO));
148   EXPECT_EQ(nullptr, test_channel.GetLogIfAll(BAR));
149 
150   EXPECT_TRUE(EnableChannel(stream_sp, 0, "chan", {"bar"}, error));
151   EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO | BAR));
152 
153   EXPECT_TRUE(EnableChannel(stream_sp, 0, "chan", {"baz"}, error));
154   EXPECT_NE(std::string::npos, error.find("unrecognized log category 'baz'"))
155       << "error: " << error;
156   EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO | BAR));
157 }
158 
159 TEST_F(LogChannelTest, EnableOptions) {
160   EXPECT_EQ(nullptr, test_channel.GetLogIfAll(FOO));
161   std::string message;
162   std::shared_ptr<llvm::raw_string_ostream> stream_sp(
163       new llvm::raw_string_ostream(message));
164   std::string error;
165   EXPECT_TRUE(
166       EnableChannel(stream_sp, LLDB_LOG_OPTION_VERBOSE, "chan", {}, error));
167 
168   Log *log = test_channel.GetLogIfAll(FOO);
169   ASSERT_NE(nullptr, log);
170   EXPECT_TRUE(log->GetVerbose());
171 }
172 
173 TEST_F(LogChannelTest, Disable) {
174   EXPECT_EQ(nullptr, test_channel.GetLogIfAll(FOO));
175   std::string message;
176   std::shared_ptr<llvm::raw_string_ostream> stream_sp(
177       new llvm::raw_string_ostream(message));
178   std::string error;
179   EXPECT_TRUE(EnableChannel(stream_sp, 0, "chan", {"foo", "bar"}, error));
180   EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO | BAR));
181 
182   EXPECT_TRUE(DisableChannel("chan", {"bar"}, error));
183   EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO));
184   EXPECT_EQ(nullptr, test_channel.GetLogIfAll(BAR));
185 
186   EXPECT_TRUE(DisableChannel("chan", {"baz"}, error));
187   EXPECT_NE(std::string::npos, error.find("unrecognized log category 'baz'"))
188       << "error: " << error;
189   EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO));
190   EXPECT_EQ(nullptr, test_channel.GetLogIfAll(BAR));
191 
192   EXPECT_TRUE(DisableChannel("chan", {}, error));
193   EXPECT_EQ(nullptr, test_channel.GetLogIfAny(FOO | BAR));
194 }
195 
196 TEST_F(LogChannelTest, List) {
197   std::string list;
198   EXPECT_TRUE(ListCategories("chan", list));
199   std::string expected =
200       R"(Logging categories for 'chan':
201   all - all available logging categories
202   default - default set of logging categories
203   foo - log foo
204   bar - log bar
205 )";
206   EXPECT_EQ(expected, list);
207 
208   EXPECT_FALSE(ListCategories("chanchan", list));
209   EXPECT_EQ("Invalid log channel 'chanchan'.\n", list);
210 }
211 
212 TEST_F(LogChannelEnabledTest, log_options) {
213   std::string Err;
214   EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
215   EXPECT_TRUE(EnableChannel(getStream(), LLDB_LOG_OPTION_THREADSAFE, "chan", {},
216                             Err));
217   EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
218 
219   {
220     EXPECT_TRUE(EnableChannel(getStream(), LLDB_LOG_OPTION_PREPEND_SEQUENCE,
221                               "chan", {}, Err));
222     llvm::StringRef Msg = logAndTakeOutput("Hello World");
223     int seq_no;
224     EXPECT_EQ(1, sscanf(Msg.str().c_str(), "%d Hello World", &seq_no));
225   }
226 
227   {
228     EXPECT_TRUE(EnableChannel(getStream(), LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION,
229                               "chan", {}, Err));
230     llvm::StringRef Msg = logAndTakeOutput("Hello World");
231     char File[12];
232     char Function[17];
233 
234     sscanf(Msg.str().c_str(), "%[^:]:%s                                 Hello World", File, Function);
235     EXPECT_STRCASEEQ("LogTest.cpp", File);
236     EXPECT_STREQ("logAndTakeOutput", Function);
237   }
238 
239   EXPECT_TRUE(EnableChannel(
240       getStream(), LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD, "chan", {}, Err));
241   EXPECT_EQ(llvm::formatv("[{0,0+4}/{1,0+4}] Hello World\n", ::getpid(),
242                           llvm::get_threadid())
243                 .str(),
244             logAndTakeOutput("Hello World"));
245 }
246 
247 TEST_F(LogChannelEnabledTest, LLDB_LOG_ERROR) {
248   LLDB_LOG_ERROR(getLog(), llvm::Error::success(), "Foo failed: {0}");
249   ASSERT_EQ("", takeOutput());
250 
251   LLDB_LOG_ERROR(getLog(),
252                  llvm::make_error<llvm::StringError>(
253                      "My Error", llvm::inconvertibleErrorCode()),
254                  "Foo failed: {0}");
255   ASSERT_EQ("Foo failed: My Error\n", takeOutput());
256 
257   // Doesn't log, but doesn't assert either
258   LLDB_LOG_ERROR(nullptr,
259                  llvm::make_error<llvm::StringError>(
260                      "My Error", llvm::inconvertibleErrorCode()),
261                  "Foo failed: {0}");
262 }
263 
264 TEST_F(LogChannelEnabledTest, LogThread) {
265   // Test that we are able to concurrently write to a log channel and disable
266   // it.
267   std::string err;
268 
269   // Start logging on one thread. Concurrently, try disabling the log channel.
270   std::thread log_thread([this] { LLDB_LOG(getLog(), "Hello World"); });
271   EXPECT_TRUE(DisableChannel("chan", {}, err));
272   log_thread.join();
273 
274   // The log thread either managed to write to the log in time, or it didn't. In
275   // either case, we should not trip any undefined behavior (run the test under
276   // TSAN to verify this).
277   EXPECT_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));
278 }
279 
280 TEST_F(LogChannelEnabledTest, LogVerboseThread) {
281   // Test that we are able to concurrently check the verbose flag of a log
282   // channel and enable it.
283   std::string err;
284 
285   // Start logging on one thread. Concurrently, try enabling the log channel
286   // (with different log options).
287   std::thread log_thread([this] { LLDB_LOGV(getLog(), "Hello World"); });
288   EXPECT_TRUE(
289       EnableChannel(getStream(), LLDB_LOG_OPTION_VERBOSE, "chan", {}, err));
290   log_thread.join();
291 
292   // The log thread either managed to write to the log, or it didn't. In either
293   // case, we should not trip any undefined behavior (run the test under TSAN to
294   // verify this).
295   EXPECT_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));
296 }
297 
298 TEST_F(LogChannelEnabledTest, LogGetLogThread) {
299   // Test that we are able to concurrently get mask of a Log object and disable
300   // it.
301   std::string err;
302 
303   // Try fetching the log mask on one thread. Concurrently, try disabling the
304   // log channel.
305   uint32_t mask;
306   std::thread log_thread([this, &mask] { mask = getLog()->GetMask().Get(); });
307   EXPECT_TRUE(DisableChannel("chan", {}, err));
308   log_thread.join();
309 
310   // The mask should be either zero of "FOO". In either case, we should not trip
311   // any undefined behavior (run the test under TSAN to verify this).
312   EXPECT_THAT(mask, testing::AnyOf(0, FOO));
313 }
314