maxjhandsome
/
llvm-project
forked from OSchip/llvm-project
1
0
Fork 0
Code Issues Pull Requests Packages Releases Wiki Activity

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
This commit is contained in:
Pavel Labath 2017-01-18 11:00:26 +00:00
parent ee6d7186c3
commit 107d9bbd6c
7 changed files with 165 additions and 65 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

34
lldb/include/lldb/Core/Log.h
View File

@ -10,14 +10,6 @@
#ifndef liblldb_Log_h_
#define liblldb_Log_h_
// C Includes
#include <signal.h>
#include <stdarg.h>
#include <stdint.h>
#include <stdio.h>
// C++ Includes
// Other libraries and framework includes
// Project includes
#include "lldb/Core/ConstString.h"
#include "lldb/Core/Flags.h"
@ -25,7 +17,12 @@
#include "lldb/Core/PluginInterface.h"
#include "lldb/lldb-private.h"
// Other libraries and framework includes
#include "llvm/Support/FormatVariadic.h"
// C++ Includes
#include <cstdarg>
#include <cstdint>
// C Includes
//----------------------------------------------------------------------
// Logging Options
@ -39,6 +36,7 @@
#define LLDB_LOG_OPTION_PREPEND_THREAD_NAME (1U << 6)
#define LLDB_LOG_OPTION_BACKTRACE (1U << 7)
#define LLDB_LOG_OPTION_APPEND (1U << 8)
#define LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION (1U << 9)
//----------------------------------------------------------------------
// Logging Functions
@ -109,8 +107,10 @@ public:
void PutCString(const char *cstr);
void PutString(llvm::StringRef str);
template <typename... Args> void Format(const char *fmt, Args &&... args) {
PutString(llvm::formatv(fmt, std::forward<Args>(args)...).str());
template <typename... Args>
void Format(llvm::StringRef file, llvm::StringRef function,
const char *format, Args &&... args) {
Format(file, function, llvm::formatv(format, std::forward<Args>(args)...));
}
// CLEANUP: Add llvm::raw_ostream &Stream() function.
@ -155,6 +155,13 @@ protected:
private:
DISALLOW_COPY_AND_ASSIGN(Log);
void WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file,
llvm::StringRef function);
void WriteMessage(const std::string &message);
void Format(llvm::StringRef file, llvm::StringRef function,
const llvm::formatv_object_base &payload);
};
class LogChannel : public PluginInterface {
@ -186,4 +193,11 @@ private:
} // namespace lldb_private
#define LLDB_LOG(log, ...) \
do { \
::lldb_private::Log *log_private = (log); \
if (log_private) \
log_private->Format(__FILE__, __FUNCTION__, __VA_ARGS__); \
} while (0)
#endif // liblldb_Log_h_

3
lldb/source/Commands/CommandObjectLog.cpp
View File

@ -48,6 +48,7 @@ static OptionDefinition g_log_options[] = {
{ LLDB_OPT_SET_1, false, "thread-name",'n', OptionParser::eNoArgument, nullptr, nullptr, 0, eArgTypeNone, "Prepend all log lines with the thread name for the thread that generates the log line." },
{ LLDB_OPT_SET_1, false, "stack", 'S', OptionParser::eNoArgument, nullptr, nullptr, 0, eArgTypeNone, "Append a stack backtrace to each log line." },
{ LLDB_OPT_SET_1, false, "append", 'a', OptionParser::eNoArgument, nullptr, nullptr, 0, eArgTypeNone, "Append to the log file instead of overwriting." },
{ LLDB_OPT_SET_1, false, "file-function",'F',OptionParser::eNoArgument, nullptr, nullptr, 0, eArgTypeNone, "Prepend the names of files and function that generate the logs." },
// clang-format on
};
@ -130,6 +131,8 @@ public:
case 'a':
log_options |= LLDB_LOG_OPTION_APPEND;
break;
case 'F':
log_options |= LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION;
default:
error.SetErrorStringWithFormat("unrecognized option '%c'",
short_option);

124
lldb/source/Core/Log.cpp
View File

@ -20,6 +20,7 @@
// Other libraries and framework includes
#include "llvm/ADT/SmallString.h"
#include "llvm/Support/Chrono.h"
#include "llvm/Support/Path.h"
#include "llvm/Support/Signals.h"
#include "llvm/Support/raw_ostream.h"
@ -69,58 +70,18 @@ void Log::Printf(const char *format, ...) {
// a valid file handle, we also log to the file.
//----------------------------------------------------------------------
void Log::VAPrintf(const char *format, va_list args) {
// Make a copy of our stream shared pointer in case someone disables our
// log while we are logging and releases the stream
StreamSP stream_sp(m_stream_sp);
if (stream_sp) {
static uint32_t g_sequence_id = 0;
StreamString header;
std::string message_string;
llvm::raw_string_ostream message(message_string);
WriteHeader(message, "", "");
// Add a sequence ID if requested
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE))
header.Printf("%u ", ++g_sequence_id);
char *text;
vasprintf(&text, format, args);
message << text;
free(text);
// Timestamp if requested
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) {
auto now = std::chrono::duration<double>(
std::chrono::system_clock::now().time_since_epoch());
header.Printf("%.9f ", now.count());
}
message << "\n";
// Add the process and thread if requested
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD))
header.Printf("[%4.4x/%4.4" PRIx64 "]: ", getpid(),
Host::GetCurrentThreadID());
// Add the thread name if requested
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) {
llvm::SmallString<32> thread_name;
ThisThread::GetName(thread_name);
if (!thread_name.empty())
header.Printf("%s ", thread_name.c_str());
}
header.PrintfVarArg(format, args);
header.PutCString("\n");
if (m_options.Test(LLDB_LOG_OPTION_BACKTRACE)) {
std::string back_trace;
llvm::raw_string_ostream stream(back_trace);
llvm::sys::PrintStackTrace(stream);
stream.flush();
header.PutCString(back_trace);
}
if (m_options.Test(LLDB_LOG_OPTION_THREADSAFE)) {
static std::recursive_mutex g_LogThreadedMutex;
std::lock_guard<std::recursive_mutex> guard(g_LogThreadedMutex);
stream_sp->PutCString(header.GetString());
stream_sp->Flush();
} else {
stream_sp->PutCString(header.GetString());
stream_sp->Flush();
}
}
WriteMessage(message.str());
}
//----------------------------------------------------------------------
@ -353,6 +314,71 @@ bool Log::GetDebug() const {
return false;
}
void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file,
llvm::StringRef function) {
static uint32_t g_sequence_id = 0;
// Add a sequence ID if requested
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE))
OS << ++g_sequence_id << " ";
// Timestamp if requested
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) {
auto now = std::chrono::duration<double>(
std::chrono::system_clock::now().time_since_epoch());
OS << llvm::formatv("{0:f9} ", now.count());
}
// Add the process and thread if requested
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD))
OS << llvm::formatv("[{0,0+4}/{1,0+4}] ", getpid(),
Host::GetCurrentThreadID());
// Add the thread name if requested
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) {
llvm::SmallString<32> thread_name;
ThisThread::GetName(thread_name);
if (!thread_name.empty())
OS << thread_name;
}
if (m_options.Test(LLDB_LOG_OPTION_BACKTRACE))
llvm::sys::PrintStackTrace(OS);
if (m_options.Test(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION) &&
(!file.empty() || !function.empty())) {
file = llvm::sys::path::filename(file).take_front(40);
function = function.take_front(40);
OS << llvm::formatv("{0,-60:60} ", (file + ":" + function).str());
}
}
void Log::WriteMessage(const std::string &message) {
// Make a copy of our stream shared pointer in case someone disables our
// log while we are logging and releases the stream
StreamSP stream_sp(m_stream_sp);
if (!stream_sp)
return;
if (m_options.Test(LLDB_LOG_OPTION_THREADSAFE)) {
static std::recursive_mutex g_LogThreadedMutex;
std::lock_guard<std::recursive_mutex> guard(g_LogThreadedMutex);
stream_sp->PutCString(message.c_str());
stream_sp->Flush();
} else {
stream_sp->PutCString(message.c_str());
stream_sp->Flush();
}
}
void Log::Format(llvm::StringRef file, llvm::StringRef function,
const llvm::formatv_object_base &payload) {
std::string message_string;
llvm::raw_string_ostream message(message_string);
WriteHeader(message, file, function);
message << payload << "\n";
WriteMessage(message.str());
}
LogChannelSP LogChannel::FindPlugin(const char *plugin_name) {
LogChannelSP log_channel_sp;
LogChannelMap &channel_map = GetChannelMap();

4
lldb/source/Plugins/ExpressionParser/Clang/IRForTarget.cpp
View File

@ -512,12 +512,10 @@ bool IRForTarget::RewriteObjCConstString(llvm::GlobalVariable *ns_str,
break;
default:
encoding_flags = 0x0600; /* fall back to 0x0600, kCFStringEncodingASCII */
if (log) {
log->Format("Encountered an Objective-C constant string with unusual "
LLDB_LOG(log, "Encountered an Objective-C constant string with unusual "
"element size {0}",
string_array->getElementByteSize());
}
}
Constant *encoding_arg = ConstantInt::get(i32_ty, encoding_flags, false);
Constant *isExternal_arg =
ConstantInt::get(i8_ty, 0x0, false); /* 0x0 is false */

6
lldb/tools/lldb-server/lldb-gdbserver.cpp
View File

@ -424,8 +424,10 @@ int main_gdbserver(int argc, char *argv[]) {
exit(option_error);
}
if (!LLDBServerUtilities::SetupLogging(log_file, log_channels,
LLDB_LOG_OPTION_PREPEND_TIMESTAMP))
if (!LLDBServerUtilities::SetupLogging(
log_file, log_channels,
LLDB_LOG_OPTION_PREPEND_TIMESTAMP |
LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION))
return -1;
Log *log(lldb_private::GetLogIfAnyCategoriesSet(GDBR_LOG_VERBOSE));

1
lldb/unittests/Core/CMakeLists.txt
View File

@ -4,6 +4,7 @@ add_lldb_unittest(LLDBCoreTests
DataExtractorTest.cpp
ErrorTest.cpp
ListenerTest.cpp
LogTest.cpp
ScalarTest.cpp
StructuredDataTest.cpp
TimerTest.cpp

56
lldb/unittests/Core/LogTest.cpp Normal file
View File

@ -0,0 +1,56 @@
//===-- LogTest.cpp ---------------------------------------------*- C++ -*-===//
//
// The LLVM Compiler Infrastructure
//
// This file is distributed under the University of Illinois Open Source
// License. See LICENSE.TXT for details.
//
//===----------------------------------------------------------------------===//
#include "lldb/Core/Log.h"
#include "lldb/Core/StreamString.h"
#include "lldb/Host/Host.h"
#include "gtest/gtest.h"
using namespace lldb;
using namespace lldb_private;
static std::string GetLogString(uint32_t log_options, const char *format,
int arg) {
std::shared_ptr<StreamString> stream_sp(new StreamString());
Log log_(stream_sp);
log_.GetOptions().Reset(log_options);
Log *log = &log_;
LLDB_LOG(log, format, arg);
return stream_sp->GetString();
}
TEST(LogTest, LLDB_LOG_nullptr) {
Log *log = nullptr;
LLDB_LOG(log, "{0}", 0); // Shouldn't crash
}
TEST(LogTest, 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}/{1}] Hello World 47\n",
Host::GetCurrentProcessID(),
Host::GetCurrentThreadID())
.str(),
GetLogString(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD,
"Hello World {0}", 47));
}