Replace WINLOG_*** macros with LLDB_LOG

Summary:
The main difference here is that in the WINLOG macros you can specify
log categories per call, whereas here you have to go the usual lldb
route of getting a Log* variable first. While this means you have to
write at least two statements, it usually means that each statement will
fit on a single line, whereas fitting the WINLOG invocation on a single
line was almost impossible. So the total size of code does not increase
even in functions with a single log statement, and functions with more
logging get shorter.

The downside here is reduced flexibility in specifying the log
categories, which a couple of functions used quite heavily (e.g.
RefreshStateAfterStop). For these I chose a single category used most
prominently and put everything into that, although a solution with
multiple log variables is definitely possible.

Reviewers: zturner, amccarth

Subscribers: lldb-commits

Differential Revision: https://reviews.llvm.org/D30172

llvm-svn: 295822
This commit is contained in:
Pavel Labath
2017-02-22 10:38:02 +00:00
parent 048b3ece1d
commit a385d2c1b6
6 changed files with 244 additions and 374 deletions

View File

@@ -61,9 +61,8 @@ DebuggerThread::DebuggerThread(DebugDelegateSP debug_delegate)
DebuggerThread::~DebuggerThread() { ::CloseHandle(m_debugging_ended_event); }
Error DebuggerThread::DebugLaunch(const ProcessLaunchInfo &launch_info) {
WINLOG_IFALL(WINDOWS_LOG_PROCESS,
"DebuggerThread::DebugLaunch launching '%s'",
launch_info.GetExecutableFile().GetPath().c_str());
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_PROCESS);
LLDB_LOG(log, "launching '{0}'", launch_info.GetExecutableFile().GetPath());
Error error;
DebugLaunchContext *context = new DebugLaunchContext(this, launch_info);
@@ -71,19 +70,16 @@ Error DebuggerThread::DebugLaunch(const ProcessLaunchInfo &launch_info) {
"lldb.plugin.process-windows.slave[?]", DebuggerThreadLaunchRoutine,
context, &error));
if (!error.Success()) {
WINERR_IFALL(WINDOWS_LOG_PROCESS,
"DebugLaunch couldn't launch debugger thread. %s",
error.AsCString());
}
if (!error.Success())
LLDB_LOG(log, "couldn't launch debugger thread. {0}", error);
return error;
}
Error DebuggerThread::DebugAttach(lldb::pid_t pid,
const ProcessAttachInfo &attach_info) {
WINLOG_IFALL(WINDOWS_LOG_PROCESS,
"DebuggerThread::DebugAttach attaching to '%llu'", pid);
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_PROCESS);
LLDB_LOG(log, "attaching to '{0}'", pid);
Error error;
DebugAttachContext *context = new DebugAttachContext(this, pid, attach_info);
@@ -91,11 +87,8 @@ Error DebuggerThread::DebugAttach(lldb::pid_t pid,
"lldb.plugin.process-windows.slave[?]", DebuggerThreadAttachRoutine,
context, &error));
if (!error.Success()) {
WINERR_IFALL(WINDOWS_LOG_PROCESS,
"DebugAttach couldn't attach to process '%llu'. %s", pid,
error.AsCString());
}
if (!error.Success())
LLDB_LOG(log, "couldn't attach to process '{0}'. {1}", pid, error);
return error;
}
@@ -123,9 +116,9 @@ lldb::thread_result_t DebuggerThread::DebuggerThreadLaunchRoutine(
// thread routine has exited.
std::shared_ptr<DebuggerThread> this_ref(shared_from_this());
WINLOG_IFALL(WINDOWS_LOG_PROCESS,
"DebuggerThread preparing to launch '%s' on background thread.",
launch_info.GetExecutableFile().GetPath().c_str());
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_PROCESS);
LLDB_LOG(log, "preparing to launch '{0}' on background thread.",
launch_info.GetExecutableFile().GetPath());
Error error;
ProcessLauncherWindows launcher;
@@ -154,9 +147,9 @@ lldb::thread_result_t DebuggerThread::DebuggerThreadAttachRoutine(
// thread routine has exited.
std::shared_ptr<DebuggerThread> this_ref(shared_from_this());
WINLOG_IFALL(WINDOWS_LOG_PROCESS, "DebuggerThread preparing to attach to "
"process '%llu' on background thread.",
pid);
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_PROCESS);
LLDB_LOG(log, "preparing to attach to process '{0}' on background thread.",
pid);
if (!DebugActiveProcess((DWORD)pid)) {
Error error(::GetLastError(), eErrorTypeWin32);
@@ -179,9 +172,8 @@ Error DebuggerThread::StopDebugging(bool terminate) {
lldb::pid_t pid = m_process.GetProcessId();
WINLOG_IFALL(WINDOWS_LOG_PROCESS,
"StopDebugging('%s') called (inferior=%I64u).",
(terminate ? "true" : "false"), pid);
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_PROCESS);
LLDB_LOG(log, "terminate = {0}, inferior={1}.", terminate, pid);
// Set m_is_shutting_down to true if it was false. Return if it was already
// true.
@@ -200,10 +192,9 @@ Error DebuggerThread::StopDebugging(bool terminate) {
// next debug
// event we get is the exit process event, and not some other event.
BOOL terminate_suceeded = TerminateProcess(handle, 0);
WINLOG_IFALL(WINDOWS_LOG_PROCESS, "StopDebugging called "
"TerminateProcess(0x%p, 0) "
"(inferior=%I64u), success='%s'",
handle, pid, (terminate_suceeded ? "true" : "false"));
LLDB_LOG(log,
"calling TerminateProcess({0}, 0) (inferior={1}), success={2}",
handle, pid, terminate_suceeded);
}
// If we're stuck waiting for an exception to continue (e.g. the user is at a
@@ -213,9 +204,7 @@ Error DebuggerThread::StopDebugging(bool terminate) {
// to make sure that the very next call to WaitForDebugEvent is an exit
// process event.
if (m_active_exception.get()) {
WINLOG_IFANY(WINDOWS_LOG_PROCESS | WINDOWS_LOG_EXCEPTION,
"StopDebugging masking active exception");
LLDB_LOG(log, "masking active exception");
ContinueAsyncException(ExceptionResult::MaskException);
}
@@ -231,26 +220,19 @@ Error DebuggerThread::StopDebugging(bool terminate) {
}
}
WINLOG_IFALL(
WINDOWS_LOG_PROCESS,
"StopDebugging waiting for detach from process %llu to complete.", pid);
LLDB_LOG(log, "waiting for detach from process {0} to complete.", pid);
DWORD wait_result = WaitForSingleObject(m_debugging_ended_event, 5000);
if (wait_result != WAIT_OBJECT_0) {
error.SetError(GetLastError(), eErrorTypeWin32);
WINERR_IFALL(WINDOWS_LOG_PROCESS,
"StopDebugging WaitForSingleObject(0x%p, 5000) returned %lu",
m_debugging_ended_event, wait_result);
} else {
WINLOG_IFALL(
WINDOWS_LOG_PROCESS,
"StopDebugging detach from process %llu completed successfully.", pid);
}
LLDB_LOG(log, "error: WaitForSingleObject({0}, 5000) returned {1}",
m_debugging_ended_event, wait_result);
} else
LLDB_LOG(log, "detach from process {0} completed successfully.", pid);
if (!error.Success()) {
WINERR_IFALL(WINDOWS_LOG_PROCESS, "StopDebugging encountered an error "
"while trying to stop process %llu. %s",
pid, error.AsCString());
LLDB_LOG(log, "encountered an error while trying to stop process {0}. {1}",
pid, error);
}
return error;
}
@@ -259,10 +241,10 @@ void DebuggerThread::ContinueAsyncException(ExceptionResult result) {
if (!m_active_exception.get())
return;
WINLOG_IFANY(
WINDOWS_LOG_PROCESS | WINDOWS_LOG_EXCEPTION,
"ContinueAsyncException called for inferior process %I64u, broadcasting.",
m_process.GetProcessId());
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_PROCESS |
WINDOWS_LOG_EXCEPTION);
LLDB_LOG(log, "broadcasting for inferior process {0}.",
m_process.GetProcessId());
m_active_exception.reset();
m_exception_pred.SetValue(result, eBroadcastAlways);
@@ -278,11 +260,12 @@ void DebuggerThread::FreeProcessHandles() {
}
void DebuggerThread::DebugLoop() {
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT);
DEBUG_EVENT dbe = {};
bool should_debug = true;
WINLOG_IFALL(WINDOWS_LOG_EVENT, "Entering WaitForDebugEvent loop");
LLDB_LOGV(log, "Entering WaitForDebugEvent loop");
while (should_debug) {
WINLOGV_IFALL(WINDOWS_LOG_EVENT, "Calling WaitForDebugEvent");
LLDB_LOGV(log, "Calling WaitForDebugEvent");
BOOL wait_result = WaitForDebugEvent(&dbe, INFINITE);
if (wait_result) {
DWORD continue_status = DBG_CONTINUE;
@@ -331,11 +314,9 @@ void DebuggerThread::DebugLoop() {
break;
}
WINLOGV_IFALL(
WINDOWS_LOG_EVENT,
"DebugLoop calling ContinueDebugEvent(%lu, %lu, %lu) on thread %lu.",
dbe.dwProcessId, dbe.dwThreadId, continue_status,
::GetCurrentThreadId());
LLDB_LOGV(log, "calling ContinueDebugEvent({0}, {1}, {2}) on thread {3}.",
dbe.dwProcessId, dbe.dwThreadId, continue_status,
::GetCurrentThreadId());
::ContinueDebugEvent(dbe.dwProcessId, dbe.dwThreadId, continue_status);
@@ -343,23 +324,23 @@ void DebuggerThread::DebugLoop() {
should_debug = false;
}
} else {
WINERR_IFALL(
WINDOWS_LOG_EVENT,
"DebugLoop returned FALSE from WaitForDebugEvent. Error = %lu",
::GetLastError());
LLDB_LOG(log, "returned FALSE from WaitForDebugEvent. Error = {0}",
::GetLastError());
should_debug = false;
}
}
FreeProcessHandles();
WINLOG_IFALL(WINDOWS_LOG_EVENT, "WaitForDebugEvent loop completed, exiting.");
LLDB_LOG(log, "WaitForDebugEvent loop completed, exiting.");
SetEvent(m_debugging_ended_event);
}
ExceptionResult
DebuggerThread::HandleExceptionEvent(const EXCEPTION_DEBUG_INFO &info,
DWORD thread_id) {
Log *log =
ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT | WINDOWS_LOG_EXCEPTION);
if (m_is_shutting_down) {
// A breakpoint that occurs while `m_pid_to_detach` is non-zero is a magic
// exception that
@@ -367,10 +348,8 @@ DebuggerThread::HandleExceptionEvent(const EXCEPTION_DEBUG_INFO &info,
// debug loop.
if (m_pid_to_detach != 0 &&
info.ExceptionRecord.ExceptionCode == EXCEPTION_BREAKPOINT) {
WINLOG_IFANY(WINDOWS_LOG_EVENT | WINDOWS_LOG_EXCEPTION |
WINDOWS_LOG_PROCESS,
"Breakpoint exception is cue to detach from process 0x%lx",
m_pid_to_detach.load());
LLDB_LOG(log, "Breakpoint exception is cue to detach from process {0:x}",
m_pid_to_detach.load());
::DebugActiveProcessStop(m_pid_to_detach);
m_detached = true;
}
@@ -385,36 +364,29 @@ DebuggerThread::HandleExceptionEvent(const EXCEPTION_DEBUG_INFO &info,
m_active_exception.reset(
new ExceptionRecord(info.ExceptionRecord, thread_id));
WINLOG_IFANY(WINDOWS_LOG_EVENT | WINDOWS_LOG_EXCEPTION,
"HandleExceptionEvent encountered %s chance exception 0x%lx on "
"thread 0x%lx",
first_chance ? "first" : "second",
info.ExceptionRecord.ExceptionCode, thread_id);
LLDB_LOG(log, "encountered {0} chance exception {1:x} on thread {2:x}",
first_chance ? "first" : "second",
info.ExceptionRecord.ExceptionCode, thread_id);
ExceptionResult result =
m_debug_delegate->OnDebugException(first_chance, *m_active_exception);
m_exception_pred.SetValue(result, eBroadcastNever);
WINLOG_IFANY(WINDOWS_LOG_EVENT | WINDOWS_LOG_EXCEPTION,
"DebuggerThread::HandleExceptionEvent waiting for ExceptionPred "
"!= BreakInDebugger");
LLDB_LOG(log, "waiting for ExceptionPred != BreakInDebugger");
m_exception_pred.WaitForValueNotEqualTo(ExceptionResult::BreakInDebugger,
result);
WINLOG_IFANY(WINDOWS_LOG_EVENT | WINDOWS_LOG_EXCEPTION,
"DebuggerThread::HandleExceptionEvent got ExceptionPred = %u",
m_exception_pred.GetValue());
LLDB_LOG(log, "got ExceptionPred = {0}", (int)m_exception_pred.GetValue());
return result;
}
DWORD
DebuggerThread::HandleCreateThreadEvent(const CREATE_THREAD_DEBUG_INFO &info,
DWORD thread_id) {
WINLOG_IFANY(WINDOWS_LOG_EVENT | WINDOWS_LOG_THREAD,
"HandleCreateThreadEvent Thread 0x%lx spawned in process %llu",
thread_id, m_process.GetProcessId());
Log *log =
ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT | WINDOWS_LOG_THREAD);
LLDB_LOG(log, "Thread {0:x} spawned in process {1}", thread_id,
m_process.GetProcessId());
HostThread thread(info.hThread);
thread.GetNativeThread().SetOwnsHandle(false);
m_debug_delegate->OnCreateThread(thread);
@@ -424,10 +396,11 @@ DebuggerThread::HandleCreateThreadEvent(const CREATE_THREAD_DEBUG_INFO &info,
DWORD
DebuggerThread::HandleCreateProcessEvent(const CREATE_PROCESS_DEBUG_INFO &info,
DWORD thread_id) {
Log *log =
ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT | WINDOWS_LOG_PROCESS);
uint32_t process_id = ::GetProcessId(info.hProcess);
WINLOG_IFANY(WINDOWS_LOG_EVENT | WINDOWS_LOG_PROCESS,
"HandleCreateProcessEvent process %u spawned", process_id);
LLDB_LOG(log, "process {0} spawned", process_id);
std::string thread_name;
llvm::raw_string_ostream name_stream(thread_name);
@@ -452,10 +425,10 @@ DebuggerThread::HandleCreateProcessEvent(const CREATE_PROCESS_DEBUG_INFO &info,
DWORD
DebuggerThread::HandleExitThreadEvent(const EXIT_THREAD_DEBUG_INFO &info,
DWORD thread_id) {
WINLOG_IFANY(
WINDOWS_LOG_EVENT | WINDOWS_LOG_THREAD,
"HandleExitThreadEvent Thread %lu exited with code %lu in process %llu",
thread_id, info.dwExitCode, m_process.GetProcessId());
Log *log =
ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT | WINDOWS_LOG_THREAD);
LLDB_LOG(log, "Thread {0} exited with code {1} in process {2}", thread_id,
info.dwExitCode, m_process.GetProcessId());
m_debug_delegate->OnExitThread(thread_id, info.dwExitCode);
return DBG_CONTINUE;
}
@@ -463,9 +436,10 @@ DebuggerThread::HandleExitThreadEvent(const EXIT_THREAD_DEBUG_INFO &info,
DWORD
DebuggerThread::HandleExitProcessEvent(const EXIT_PROCESS_DEBUG_INFO &info,
DWORD thread_id) {
WINLOG_IFANY(WINDOWS_LOG_EVENT | WINDOWS_LOG_THREAD,
"HandleExitProcessEvent process %llu exited with code %lu",
m_process.GetProcessId(), info.dwExitCode);
Log *log =
ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT | WINDOWS_LOG_THREAD);
LLDB_LOG(log, "process {0} exited with code {1}", m_process.GetProcessId(),
info.dwExitCode);
m_debug_delegate->OnExitProcess(info.dwExitCode);
@@ -476,11 +450,11 @@ DebuggerThread::HandleExitProcessEvent(const EXIT_PROCESS_DEBUG_INFO &info,
DWORD
DebuggerThread::HandleLoadDllEvent(const LOAD_DLL_DEBUG_INFO &info,
DWORD thread_id) {
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT);
if (info.hFile == nullptr) {
// Not sure what this is, so just ignore it.
WINWARN_IFALL(WINDOWS_LOG_EVENT, "Inferior %llu - HandleLoadDllEvent has "
"a NULL file handle, returning...",
m_process.GetProcessId());
LLDB_LOG(log, "Warning: Inferior {0} has a NULL file handle, returning...",
m_process.GetProcessId());
return DBG_CONTINUE;
}
@@ -502,16 +476,15 @@ DebuggerThread::HandleLoadDllEvent(const LOAD_DLL_DEBUG_INFO &info,
ModuleSpec module_spec(file_spec);
lldb::addr_t load_addr = reinterpret_cast<lldb::addr_t>(info.lpBaseOfDll);
WINLOG_IFALL(WINDOWS_LOG_EVENT, "Inferior %I64u - HandleLoadDllEvent DLL "
"'%s' loaded at address 0x%p...",
m_process.GetProcessId(), path, info.lpBaseOfDll);
LLDB_LOG(log, "Inferior {0} - DLL '{1}' loaded at address {2:x}...",
m_process.GetProcessId(), path, info.lpBaseOfDll);
m_debug_delegate->OnLoadDll(module_spec, load_addr);
} else {
WINERR_IFALL(WINDOWS_LOG_EVENT, "Inferior %llu - HandleLoadDllEvent Error "
"%lu occurred calling "
"GetFinalPathNameByHandle",
m_process.GetProcessId(), ::GetLastError());
LLDB_LOG(
log,
"Inferior {0} - Error {1} occurred calling GetFinalPathNameByHandle",
m_process.GetProcessId(), ::GetLastError());
}
// Windows does not automatically close info.hFile, so we need to do it.
::CloseHandle(info.hFile);
@@ -521,9 +494,9 @@ DebuggerThread::HandleLoadDllEvent(const LOAD_DLL_DEBUG_INFO &info,
DWORD
DebuggerThread::HandleUnloadDllEvent(const UNLOAD_DLL_DEBUG_INFO &info,
DWORD thread_id) {
WINLOG_IFALL(WINDOWS_LOG_EVENT,
"HandleUnloadDllEvent process %llu unloading DLL at addr 0x%p.",
m_process.GetProcessId(), info.lpBaseOfDll);
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT);
LLDB_LOG(log, "process {0} unloading DLL at addr {1:x}.",
m_process.GetProcessId(), info.lpBaseOfDll);
m_debug_delegate->OnUnloadDll(
reinterpret_cast<lldb::addr_t>(info.lpBaseOfDll));
@@ -538,9 +511,9 @@ DebuggerThread::HandleODSEvent(const OUTPUT_DEBUG_STRING_INFO &info,
DWORD
DebuggerThread::HandleRipEvent(const RIP_INFO &info, DWORD thread_id) {
WINERR_IFALL(WINDOWS_LOG_EVENT, "HandleRipEvent encountered error %lu "
"(type=%lu) in process %llu thread %lu",
info.dwError, info.dwType, m_process.GetProcessId(), thread_id);
Log *log = ProcessWindowsLog::GetLogIfAny(WINDOWS_LOG_EVENT);
LLDB_LOG(log, "encountered error {0} (type={1}) in process {2} thread {3}",
info.dwError, info.dwType, m_process.GetProcessId(), thread_id);
Error error(info.dwError, eErrorTypeWin32);
m_debug_delegate->OnDebuggerError(error, info.dwType);