Add a more succinct logging syntax
This adds the LLDB_LOG macro, which enables one to write more succinct log
statements.
if (log)
log->Printf("log something: %d", var);
becomes
LLDB_LOG(log, "log something: {0}, var);
The macro still internally does the "if(log)" dance, so the arguments are only
evaluated if logging is enabled, meaning it has the same overhead as the
previous syntax.
Additionally, the log statements will be automatically prefixed with the file
and function generating the log (if the corresponding new argument to the "log
enable" command is enabled), so one does not need to manually specify this in
the log statement.
It also uses the new llvm formatv syntax, which means we don't have to worry
about PRIx64 macros and similar, and we can log complex object (llvm::StringRef,
lldb_private::Error, ...) more easily.
Differential Revision: https://reviews.llvm.org/D27459
llvm-svn: 292360
2017-01-18 19:00:26 +08:00
|
|
|
//===-- LogTest.cpp ---------------------------------------------*- C++ -*-===//
|
|
|
|
//
|
|
|
|
// The LLVM Compiler Infrastructure
|
|
|
|
//
|
|
|
|
// This file is distributed under the University of Illinois Open Source
|
|
|
|
// License. See LICENSE.TXT for details.
|
|
|
|
//
|
|
|
|
//===----------------------------------------------------------------------===//
|
|
|
|
|
2017-01-18 20:29:51 +08:00
|
|
|
#include "gtest/gtest.h"
|
|
|
|
|
2017-03-04 04:56:28 +08:00
|
|
|
#include "lldb/Utility/Log.h"
|
2017-02-03 05:39:50 +08:00
|
|
|
#include "lldb/Utility/StreamString.h"
|
2017-02-17 21:27:42 +08:00
|
|
|
#include "llvm/Support/ManagedStatic.h"
|
2017-03-04 04:56:28 +08:00
|
|
|
#include "llvm/Support/Threading.h"
|
2017-02-21 17:58:23 +08:00
|
|
|
#include <thread>
|
Add a more succinct logging syntax
This adds the LLDB_LOG macro, which enables one to write more succinct log
statements.
if (log)
log->Printf("log something: %d", var);
becomes
LLDB_LOG(log, "log something: {0}, var);
The macro still internally does the "if(log)" dance, so the arguments are only
evaluated if logging is enabled, meaning it has the same overhead as the
previous syntax.
Additionally, the log statements will be automatically prefixed with the file
and function generating the log (if the corresponding new argument to the "log
enable" command is enabled), so one does not need to manually specify this in
the log statement.
It also uses the new llvm formatv syntax, which means we don't have to worry
about PRIx64 macros and similar, and we can log complex object (llvm::StringRef,
lldb_private::Error, ...) more easily.
Differential Revision: https://reviews.llvm.org/D27459
llvm-svn: 292360
2017-01-18 19:00:26 +08:00
|
|
|
|
|
|
|
using namespace lldb;
|
|
|
|
using namespace lldb_private;
|
|
|
|
|
2017-02-17 21:27:42 +08:00
|
|
|
enum { FOO = 1, BAR = 2 };
|
|
|
|
static constexpr Log::Category test_categories[] = {
|
2017-03-01 18:08:51 +08:00
|
|
|
{{"foo"}, {"log foo"}, FOO}, {{"bar"}, {"log bar"}, BAR},
|
2017-02-17 21:27:42 +08:00
|
|
|
};
|
|
|
|
static constexpr uint32_t default_flags = FOO;
|
|
|
|
|
|
|
|
static Log::Channel test_channel(test_categories, default_flags);
|
|
|
|
|
|
|
|
struct LogChannelTest : public ::testing::Test {
|
2017-02-21 17:58:23 +08:00
|
|
|
void TearDown() override { Log::DisableAllLogChannels(nullptr); }
|
|
|
|
|
2017-02-17 21:27:42 +08:00
|
|
|
static void SetUpTestCase() {
|
|
|
|
Log::Register("chan", test_channel);
|
|
|
|
}
|
|
|
|
|
|
|
|
static void TearDownTestCase() {
|
|
|
|
Log::Unregister("chan");
|
|
|
|
llvm::llvm_shutdown();
|
|
|
|
}
|
|
|
|
};
|
|
|
|
|
Add a more succinct logging syntax
This adds the LLDB_LOG macro, which enables one to write more succinct log
statements.
if (log)
log->Printf("log something: %d", var);
becomes
LLDB_LOG(log, "log something: {0}, var);
The macro still internally does the "if(log)" dance, so the arguments are only
evaluated if logging is enabled, meaning it has the same overhead as the
previous syntax.
Additionally, the log statements will be automatically prefixed with the file
and function generating the log (if the corresponding new argument to the "log
enable" command is enabled), so one does not need to manually specify this in
the log statement.
It also uses the new llvm formatv syntax, which means we don't have to worry
about PRIx64 macros and similar, and we can log complex object (llvm::StringRef,
lldb_private::Error, ...) more easily.
Differential Revision: https://reviews.llvm.org/D27459
llvm-svn: 292360
2017-01-18 19:00:26 +08:00
|
|
|
TEST(LogTest, LLDB_LOG_nullptr) {
|
|
|
|
Log *log = nullptr;
|
|
|
|
LLDB_LOG(log, "{0}", 0); // Shouldn't crash
|
|
|
|
}
|
|
|
|
|
2017-02-17 21:27:42 +08:00
|
|
|
TEST(LogTest, Register) {
|
|
|
|
llvm::llvm_shutdown_obj obj;
|
|
|
|
Log::Register("chan", test_channel);
|
|
|
|
Log::Unregister("chan");
|
|
|
|
Log::Register("chan", test_channel);
|
|
|
|
Log::Unregister("chan");
|
|
|
|
}
|
|
|
|
|
|
|
|
TEST(LogTest, Unregister) {
|
|
|
|
llvm::llvm_shutdown_obj obj;
|
|
|
|
Log::Register("chan", test_channel);
|
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAny(FOO));
|
2017-03-01 18:08:40 +08:00
|
|
|
const char *cat1[] = {"foo"};
|
2017-02-17 21:27:42 +08:00
|
|
|
std::string message;
|
|
|
|
std::shared_ptr<llvm::raw_string_ostream> stream_sp(
|
|
|
|
new llvm::raw_string_ostream(message));
|
|
|
|
StreamString err;
|
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", cat1, err));
|
|
|
|
EXPECT_NE(nullptr, test_channel.GetLogIfAny(FOO));
|
|
|
|
Log::Unregister("chan");
|
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAny(FOO));
|
|
|
|
}
|
|
|
|
|
|
|
|
TEST_F(LogChannelTest, Enable) {
|
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAll(FOO));
|
|
|
|
std::string message;
|
|
|
|
std::shared_ptr<llvm::raw_string_ostream> stream_sp(
|
|
|
|
new llvm::raw_string_ostream(message));
|
|
|
|
StreamString err;
|
2017-03-01 18:08:40 +08:00
|
|
|
EXPECT_FALSE(Log::EnableLogChannel(stream_sp, 0, "chanchan", {}, err));
|
2017-02-17 21:27:42 +08:00
|
|
|
EXPECT_EQ("Invalid log channel 'chanchan'.\n", err.GetString());
|
|
|
|
err.Clear();
|
|
|
|
|
2017-03-01 18:08:40 +08:00
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", {}, err));
|
|
|
|
EXPECT_EQ("", err.GetString()) << "err: " << err.GetString().str();
|
2017-02-17 21:27:42 +08:00
|
|
|
EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO));
|
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAll(BAR));
|
|
|
|
|
2017-03-01 18:08:40 +08:00
|
|
|
const char *cat2[] = {"bar"};
|
2017-02-17 21:27:42 +08:00
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", cat2, err));
|
|
|
|
EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO | BAR));
|
|
|
|
|
2017-03-01 18:08:40 +08:00
|
|
|
const char *cat3[] = {"baz"};
|
2017-02-17 21:27:42 +08:00
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", cat3, err));
|
|
|
|
EXPECT_TRUE(err.GetString().contains("unrecognized log category 'baz'"))
|
|
|
|
<< "err: " << err.GetString().str();
|
|
|
|
EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO | BAR));
|
|
|
|
}
|
|
|
|
|
2017-02-27 19:05:39 +08:00
|
|
|
TEST_F(LogChannelTest, EnableOptions) {
|
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAll(FOO));
|
|
|
|
std::string message;
|
|
|
|
std::shared_ptr<llvm::raw_string_ostream> stream_sp(
|
|
|
|
new llvm::raw_string_ostream(message));
|
|
|
|
StreamString err;
|
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, LLDB_LOG_OPTION_VERBOSE, "chan",
|
2017-03-01 18:08:40 +08:00
|
|
|
{}, err));
|
2017-02-27 19:05:39 +08:00
|
|
|
|
|
|
|
Log *log = test_channel.GetLogIfAll(FOO);
|
|
|
|
ASSERT_NE(nullptr, log);
|
|
|
|
EXPECT_TRUE(log->GetVerbose());
|
|
|
|
}
|
|
|
|
|
2017-02-17 21:27:42 +08:00
|
|
|
TEST_F(LogChannelTest, Disable) {
|
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAll(FOO));
|
2017-03-01 18:08:40 +08:00
|
|
|
const char *cat12[] = {"foo", "bar"};
|
2017-02-17 21:27:42 +08:00
|
|
|
std::string message;
|
|
|
|
std::shared_ptr<llvm::raw_string_ostream> stream_sp(
|
|
|
|
new llvm::raw_string_ostream(message));
|
|
|
|
StreamString err;
|
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", cat12, err));
|
|
|
|
EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO | BAR));
|
|
|
|
|
2017-03-01 18:08:40 +08:00
|
|
|
const char *cat2[] = {"bar"};
|
2017-02-17 21:27:42 +08:00
|
|
|
EXPECT_TRUE(Log::DisableLogChannel("chan", cat2, err));
|
|
|
|
EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO));
|
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAll(BAR));
|
|
|
|
|
2017-03-01 18:08:40 +08:00
|
|
|
const char *cat3[] = {"baz"};
|
2017-02-17 21:27:42 +08:00
|
|
|
EXPECT_TRUE(Log::DisableLogChannel("chan", cat3, err));
|
|
|
|
EXPECT_TRUE(err.GetString().contains("unrecognized log category 'baz'"))
|
|
|
|
<< "err: " << err.GetString().str();
|
|
|
|
EXPECT_NE(nullptr, test_channel.GetLogIfAll(FOO));
|
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAll(BAR));
|
|
|
|
err.Clear();
|
|
|
|
|
2017-03-01 18:08:40 +08:00
|
|
|
EXPECT_TRUE(Log::DisableLogChannel("chan", {}, err));
|
2017-02-17 21:27:42 +08:00
|
|
|
EXPECT_EQ(nullptr, test_channel.GetLogIfAny(FOO | BAR));
|
|
|
|
}
|
|
|
|
|
|
|
|
TEST_F(LogChannelTest, List) {
|
|
|
|
StreamString str;
|
|
|
|
EXPECT_TRUE(Log::ListChannelCategories("chan", str));
|
|
|
|
std::string expected =
|
|
|
|
R"(Logging categories for 'chan':
|
|
|
|
all - all available logging categories
|
|
|
|
default - default set of logging categories
|
|
|
|
foo - log foo
|
|
|
|
bar - log bar
|
|
|
|
)";
|
|
|
|
EXPECT_EQ(expected, str.GetString().str());
|
|
|
|
str.Clear();
|
|
|
|
|
|
|
|
EXPECT_FALSE(Log::ListChannelCategories("chanchan", str));
|
|
|
|
EXPECT_EQ("Invalid log channel 'chanchan'.\n", str.GetString().str());
|
|
|
|
}
|
2017-02-21 17:58:23 +08:00
|
|
|
|
2017-03-07 03:10:19 +08:00
|
|
|
static std::string GetLogString(uint32_t log_options, const char *format,
|
|
|
|
int arg) {
|
|
|
|
std::string message;
|
|
|
|
std::shared_ptr<llvm::raw_string_ostream> stream_sp(
|
|
|
|
new llvm::raw_string_ostream(message));
|
|
|
|
StreamString err;
|
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, log_options, "chan", {}, err));
|
|
|
|
|
|
|
|
Log *log = test_channel.GetLogIfAll(FOO);
|
|
|
|
EXPECT_NE(nullptr, log);
|
|
|
|
|
|
|
|
LLDB_LOG(log, format, arg);
|
|
|
|
EXPECT_TRUE(Log::DisableLogChannel("chan", {}, err));
|
|
|
|
|
|
|
|
return stream_sp->str();
|
|
|
|
}
|
|
|
|
|
|
|
|
TEST_F(LogChannelTest, log_options) {
|
|
|
|
EXPECT_EQ("Hello World 47\n", GetLogString(0, "Hello World {0}", 47));
|
|
|
|
EXPECT_EQ("Hello World 47\n",
|
|
|
|
GetLogString(LLDB_LOG_OPTION_THREADSAFE, "Hello World {0}", 47));
|
|
|
|
|
|
|
|
{
|
|
|
|
std::string msg =
|
|
|
|
GetLogString(LLDB_LOG_OPTION_PREPEND_SEQUENCE, "Hello World {0}", 47);
|
|
|
|
int seq_no;
|
|
|
|
EXPECT_EQ(1, sscanf(msg.c_str(), "%d Hello World 47", &seq_no));
|
|
|
|
}
|
|
|
|
|
|
|
|
EXPECT_EQ(
|
|
|
|
"LogTest.cpp:GetLogString Hello "
|
|
|
|
"World 47\n",
|
|
|
|
GetLogString(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION, "Hello World {0}", 47));
|
|
|
|
|
|
|
|
EXPECT_EQ(llvm::formatv("[{0,0+4}/{1,0+4}] Hello World 47\n", ::getpid(),
|
|
|
|
llvm::get_threadid())
|
|
|
|
.str(),
|
|
|
|
GetLogString(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD,
|
|
|
|
"Hello World {0}", 47));
|
|
|
|
}
|
|
|
|
|
2017-02-21 17:58:23 +08:00
|
|
|
TEST_F(LogChannelTest, LogThread) {
|
|
|
|
// Test that we are able to concurrently write to a log channel and disable
|
|
|
|
// it.
|
|
|
|
std::string message;
|
|
|
|
std::shared_ptr<llvm::raw_string_ostream> stream_sp(
|
|
|
|
new llvm::raw_string_ostream(message));
|
|
|
|
StreamString err;
|
2017-03-01 18:08:40 +08:00
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", {}, err));
|
2017-02-21 17:58:23 +08:00
|
|
|
|
|
|
|
Log *log = test_channel.GetLogIfAll(FOO);
|
|
|
|
|
|
|
|
// Start logging on one thread. Concurrently, try disabling the log channel.
|
|
|
|
std::thread log_thread([log] { LLDB_LOG(log, "Hello World"); });
|
2017-03-01 18:08:40 +08:00
|
|
|
EXPECT_TRUE(Log::DisableLogChannel("chan", {}, err));
|
2017-02-21 17:58:23 +08:00
|
|
|
log_thread.join();
|
|
|
|
|
|
|
|
// The log thread either managed to write to the log in time, or it didn't. In
|
|
|
|
// either case, we should not trip any undefined behavior (run the test under
|
|
|
|
// TSAN to verify this).
|
|
|
|
EXPECT_TRUE(stream_sp->str() == "" || stream_sp->str() == "Hello World\n")
|
|
|
|
<< "str(): " << stream_sp->str();
|
|
|
|
}
|
2017-03-09 18:16:07 +08:00
|
|
|
|
|
|
|
TEST_F(LogChannelTest, LogVerboseThread) {
|
|
|
|
// Test that we are able to concurrently check the verbose flag of a log
|
|
|
|
// channel and enable it.
|
|
|
|
std::string message;
|
|
|
|
std::shared_ptr<llvm::raw_string_ostream> stream_sp(
|
|
|
|
new llvm::raw_string_ostream(message));
|
|
|
|
StreamString err;
|
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", {}, err));
|
|
|
|
|
|
|
|
Log *log = test_channel.GetLogIfAll(FOO);
|
|
|
|
|
|
|
|
// Start logging on one thread. Concurrently, try enabling the log channel
|
|
|
|
// (with different log options).
|
|
|
|
std::thread log_thread([log] { LLDB_LOGV(log, "Hello World"); });
|
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, LLDB_LOG_OPTION_VERBOSE, "chan",
|
|
|
|
{}, err));
|
|
|
|
log_thread.join();
|
|
|
|
EXPECT_TRUE(Log::DisableLogChannel("chan", {}, err));
|
|
|
|
|
|
|
|
// The log thread either managed to write to the log, or it didn't. In either
|
|
|
|
// case, we should not trip any undefined behavior (run the test under TSAN to
|
|
|
|
// verify this).
|
|
|
|
EXPECT_TRUE(stream_sp->str() == "" || stream_sp->str() == "Hello World\n")
|
|
|
|
<< "str(): " << stream_sp->str();
|
|
|
|
}
|
|
|
|
|
|
|
|
TEST_F(LogChannelTest, LogGetLogThread) {
|
|
|
|
// Test that we are able to concurrently get mask of a Log object and disable
|
|
|
|
// it.
|
|
|
|
std::string message;
|
|
|
|
std::shared_ptr<llvm::raw_string_ostream> stream_sp(
|
|
|
|
new llvm::raw_string_ostream(message));
|
|
|
|
StreamString err;
|
|
|
|
EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", {}, err));
|
|
|
|
Log *log = test_channel.GetLogIfAll(FOO);
|
|
|
|
|
|
|
|
// Try fetching the log on one thread. Concurrently, try disabling the log
|
|
|
|
// channel.
|
|
|
|
uint32_t mask;
|
|
|
|
std::thread log_thread([log, &mask] { mask = log->GetMask().Get(); });
|
|
|
|
EXPECT_TRUE(Log::DisableLogChannel("chan", {}, err));
|
|
|
|
log_thread.join();
|
|
|
|
|
|
|
|
// The mask should be either zero of "FOO". In either case, we should not trip
|
|
|
|
// any undefined behavior (run the test under TSAN to verify this).
|
|
|
|
EXPECT_TRUE(mask == 0 || mask == FOO) << "mask: " << mask;
|
|
|
|
}
|