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