405 lines · cpp
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-exception6//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 19using namespace lldb;20using namespace lldb_private;21 22enum class TestChannel : Log::MaskType {23 FOO = Log::ChannelFlag<0>,24 BAR = Log::ChannelFlag<1>,25 LLVM_MARK_AS_BITMASK_ENUM(BAR),26};27 28LLVM_ENABLE_BITMASK_ENUMS_IN_NAMESPACE();29 30static constexpr Log::Category test_categories[] = {31 {{"foo"}, {"log foo"}, TestChannel::FOO},32 {{"bar"}, {"log bar"}, TestChannel::BAR},33};34 35static Log::Channel test_channel(test_categories, TestChannel::FOO);36 37namespace lldb_private {38template <> Log::Channel &LogChannelFor<TestChannel>() { return test_channel; }39} // namespace lldb_private40 41// Wrap enable, disable and list functions to make them easier to test.42static 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 52static 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 60static 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 66namespace {67// A test fixture which provides tests with a pre-registered channel.68struct 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 79class TestLogHandler : public LogHandler {80public: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-enabled90// channel. Additionally, the messages written to that channel are captured and91// made available via getMessage().92class 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 98protected: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 105public:106 void SetUp() override;107};108 109static 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 namespace116 117void 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(TestChannel::FOO);124 ASSERT_NE(nullptr, m_log);125}126 127llvm::StringRef LogChannelEnabledTest::takeOutput() {128 llvm::StringRef result =129 m_log_handler_sp->m_stream.str().drop_front(m_consumed_bytes);130 m_consumed_bytes += result.size();131 return result;132}133 134llvm::StringRef135LogChannelEnabledTest::logAndTakeOutput(llvm::StringRef Message) {136 LLDB_LOG(m_log, "{0}", Message);137 return takeOutput();138}139 140llvm::StringRef141LogChannelEnabledTest::logAndTakeOutputf(llvm::StringRef Message) {142 LLDB_LOGF(m_log, "%s", Message.str().c_str());143 return takeOutput();144}145 146TEST(LogTest, LLDB_LOG_nullptr) {147 Log *log = nullptr;148 LLDB_LOG(log, "{0}", 0); // Shouldn't crash149}150 151TEST(LogTest, Register) {152 llvm::llvm_shutdown_obj obj;153 Log::Register("chan", test_channel);154 Log::Unregister("chan");155 Log::Register("chan", test_channel);156 Log::Unregister("chan");157}158 159TEST(LogTest, Unregister) {160 llvm::llvm_shutdown_obj obj;161 Log::Register("chan", 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("chan");168 EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));169}170 171namespace {172static char test_baton;173static size_t callback_count = 0;174static void TestCallback(const char *data, void *baton) {175 EXPECT_STREQ("Foobar", data);176 EXPECT_EQ(&test_baton, baton);177 ++callback_count;178}179} // namespace180 181TEST(LogTest, CallbackLogHandler) {182 CallbackLogHandler handler(TestCallback, &test_baton);183 handler.Emit("Foobar");184 EXPECT_EQ(1u, callback_count);185}186 187TEST(LogHandlerTest, RotatingLogHandler) {188 RotatingLogHandler handler(3);189 190 handler.Emit("foo");191 handler.Emit("bar");192 EXPECT_EQ(GetDumpAsString(handler), "foobar");193 194 handler.Emit("baz");195 handler.Emit("qux");196 EXPECT_EQ(GetDumpAsString(handler), "barbazqux");197 198 handler.Emit("quux");199 EXPECT_EQ(GetDumpAsString(handler), "bazquxquux");200}201 202TEST(LogHandlerTest, TeeLogHandler) {203 auto handler1 = std::make_shared<RotatingLogHandler>(2);204 auto handler2 = std::make_shared<RotatingLogHandler>(2);205 TeeLogHandler handler(handler1, handler2);206 207 handler.Emit("foo");208 handler.Emit("bar");209 210 EXPECT_EQ(GetDumpAsString(*handler1), "foobar");211 EXPECT_EQ(GetDumpAsString(*handler2), "foobar");212}213 214TEST_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 235TEST_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(TestChannel::FOO);243 ASSERT_NE(nullptr, log);244 EXPECT_TRUE(log->GetVerbose());245}246 247TEST_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 269TEST_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 categories275 default - default set of logging categories276 foo - log foo277 bar - log bar278)";279 EXPECT_EQ(expected, list);280 281 EXPECT_FALSE(ListCategories("chanchan", list));282 EXPECT_EQ("Invalid log channel 'chanchan'.\n", list);283}284 285TEST_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("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("Hello World");304 char File[12];305 char Function[17];306 307 sscanf(Msg.str().c_str(),308 "%[^:]:%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("Hello World");319 char File[12];320 char Function[18];321 322 sscanf(Msg.str().c_str(),323 "%[^:]:%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 338TEST_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 either349 LLDB_LOG_ERROR(nullptr,350 llvm::make_error<llvm::StringError>(351 "My Error", llvm::inconvertibleErrorCode()),352 "Foo failed: {0}");353}354 355TEST_F(LogChannelEnabledTest, LogThread) {356 // Test that we are able to concurrently write to a log channel and disable357 // 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. In366 // either case, we should not trip any undefined behavior (run the test under367 // TSAN to verify this).368 EXPECT_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));369}370 371TEST_F(LogChannelEnabledTest, LogVerboseThread) {372 // Test that we are able to concurrently check the verbose flag of a log373 // channel and enable it.374 std::string err;375 376 // Start logging on one thread. Concurrently, try enabling the log channel377 // (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 either384 // case, we should not trip any undefined behavior (run the test under TSAN to385 // verify this).386 EXPECT_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));387}388 389TEST_F(LogChannelEnabledTest, LogGetLogThread) {390 // Test that we are able to concurrently get mask of a Log object and disable391 // it.392 std::string err;393 394 // Try fetching the log mask on one thread. Concurrently, try disabling the395 // 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 trip402 // any undefined behavior (run the test under TSAN to verify this).403 EXPECT_THAT(mask, testing::AnyOf(0, Log::MaskType(TestChannel::FOO)));404}405