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