jasonmolenda created this revision.
jasonmolenda added a project: LLDB.
Herald added a subscriber: JDevlieghere.
jasonmolenda requested review of this revision.
It can be tricky to find the important error messages when debugserver tries to
launch or attach to a process in the system console log. Add some new logging
messages to give us clear before/after logging around the critical areas, so we
can search other subsystems that might issue a console message about why the
app launch failed. These new logging messages are only intended to go to the
system console, not stdout when running debugserver from the command line,
unless logging is redirected somewhere else.
rdar://problem/67220442
Repository:
rG LLVM Github Monorepo
https://reviews.llvm.org/D94357
Files:
lldb/tools/debugserver/source/MacOSX/MachProcess.mm
lldb/tools/debugserver/source/MacOSX/MachTask.mm
lldb/tools/debugserver/source/RNBRemote.cpp
lldb/tools/debugserver/source/debugserver.cpp
Index: lldb/tools/debugserver/source/debugserver.cpp
===================================================================
--- lldb/tools/debugserver/source/debugserver.cpp
+++ lldb/tools/debugserver/source/debugserver.cpp
@@ -583,29 +583,34 @@
}
if (set_events & RNBContext::event_proc_thread_exiting) {
+ DNBLog("debugserver's process monitoring thread has exited.");
mode = eRNBRunLoopModeExit;
}
if (set_events & RNBContext::event_read_thread_exiting) {
// Out remote packet receiving thread exited, exit for now.
+ DNBLog(
+ "debugserver's packet communication to lldb has been shut down.");
if (ctx.HasValidProcessID()) {
+ nub_process_t pid = ctx.ProcessID();
// TODO: We should add code that will leave the current process
// in its current state and listen for another connection...
if (ctx.ProcessStateRunning()) {
if (ctx.GetDetachOnError()) {
- DNBLog("debugserver's event read thread is exiting, detaching "
- "from the inferior process.");
- DNBProcessDetach(ctx.ProcessID());
+ DNBLog("debugserver has a valid PID %d, it is still running. "
+ "detaching from the inferior process.",
+ pid);
+ DNBProcessDetach(pid);
} else {
- DNBLog("debugserver's event read thread is exiting, killing the "
- "inferior process.");
- DNBProcessKill(ctx.ProcessID());
+ DNBLog("debugserver killing the inferior process, pid %d.", pid);
+ DNBProcessKill(pid);
}
} else {
if (ctx.GetDetachOnError()) {
- DNBLog("debugserver's event read thread is exiting, detaching "
- "from the inferior process.");
- DNBProcessDetach(ctx.ProcessID());
+ DNBLog("debugserver has a valid PID %d but it may no longer "
+ "be running, detaching from the inferior process.",
+ pid);
+ DNBProcessDetach(pid);
}
}
}
@@ -1104,21 +1109,30 @@
if (optarg && optarg[0]) {
if (strcasecmp(optarg, "auto") == 0)
g_launch_flavor = eLaunchFlavorDefault;
- else if (strcasestr(optarg, "posix") == optarg)
+ else if (strcasestr(optarg, "posix") == optarg) {
+ DNBLog(
+ "[LaunchAttach] launch flavor is posix_spawn via cmdline option");
g_launch_flavor = eLaunchFlavorPosixSpawn;
- else if (strcasestr(optarg, "fork") == optarg)
+ } else if (strcasestr(optarg, "fork") == optarg)
g_launch_flavor = eLaunchFlavorForkExec;
#ifdef WITH_SPRINGBOARD
- else if (strcasestr(optarg, "spring") == optarg)
+ else if (strcasestr(optarg, "spring") == optarg) {
+ DNBLog(
+ "[LaunchAttach] launch flavor is SpringBoard via cmdline option");
g_launch_flavor = eLaunchFlavorSpringBoard;
+ }
#endif
#ifdef WITH_BKS
- else if (strcasestr(optarg, "backboard") == optarg)
+ else if (strcasestr(optarg, "backboard") == optarg) {
+ DNBLog("[LaunchAttach] launch flavor is BKS via cmdline option");
g_launch_flavor = eLaunchFlavorBKS;
+ }
#endif
#ifdef WITH_FBS
- else if (strcasestr(optarg, "frontboard") == optarg)
+ else if (strcasestr(optarg, "frontboard") == optarg) {
+ DNBLog("[LaunchAttach] launch flavor is FBS via cmdline option");
g_launch_flavor = eLaunchFlavorFBS;
+ }
#endif
else {
@@ -1398,6 +1412,7 @@
dup2(null, STDOUT_FILENO);
dup2(null, STDERR_FILENO);
} else if (g_applist_opt != 0) {
+ DNBLog("debugserver running in --applist mode");
// List all applications we are able to see
std::string applist_plist;
int err = ListApplications(applist_plist, false, false);
@@ -1455,6 +1470,7 @@
mode = eRNBRunLoopModeExit;
} else if (g_applist_opt != 0) {
// List all applications we are able to see
+ DNBLog("debugserver running in applist mode under lockdown");
std::string applist_plist;
if (ListApplications(applist_plist, false, false) == 0) {
DNBLogDebug("Task list: %s", applist_plist.c_str());
@@ -1631,6 +1647,8 @@
const char *proc_name = "<unknown>";
if (ctx.ArgumentCount() > 0)
proc_name = ctx.ArgumentAtIndex(0);
+ DNBLog("[LaunchAttach] Successfully launched %s (pid = %d).\n",
+ proc_name, ctx.ProcessID());
RNBLogSTDOUT("Got a connection, launched process %s (pid = %d).\n",
proc_name, ctx.ProcessID());
}
Index: lldb/tools/debugserver/source/RNBRemote.cpp
===================================================================
--- lldb/tools/debugserver/source/RNBRemote.cpp
+++ lldb/tools/debugserver/source/RNBRemote.cpp
@@ -1216,6 +1216,7 @@
PThreadEvent &events = m_ctx.Events();
if ((events.GetEventBits() & RNBContext::event_read_thread_running) ==
RNBContext::event_read_thread_running) {
+ DNBLog("debugserver about to shut down packet communications to lldb.");
m_comm.Disconnect(true);
struct timespec timeout_abstime;
DNBTimer::OffsetTimeOfDay(&timeout_abstime, 2, 0);
@@ -3925,6 +3926,8 @@
return HandlePacket_ILLFORMED(
__FILE__, __LINE__, p, "non-hex char in arg on 'vAttachWait' pkt");
}
+ DNBLog("[LaunchAttach] START %d vAttachWait for process name '%s'",
+ getpid(), attach_name.c_str());
const bool ignore_existing = true;
attach_pid = DNBProcessAttachWait(
&m_ctx, attach_name.c_str(), ignore_existing, NULL, 1000, err_str,
@@ -3938,6 +3941,9 @@
"non-hex char in arg on 'vAttachOrWait' pkt");
}
const bool ignore_existing = false;
+ DNBLog("[LaunchAttach] START %d vAttachWaitOrWait for process name "
+ "'%s'",
+ getpid(), attach_name.c_str());
attach_pid = DNBProcessAttachWait(
&m_ctx, attach_name.c_str(), ignore_existing, NULL, 1000, err_str,
sizeof(err_str), RNBRemoteShouldCancelCallback);
@@ -3948,6 +3954,9 @@
__FILE__, __LINE__, p, "non-hex char in arg on 'vAttachName' pkt");
}
+ DNBLog("[LaunchAttach] START %d vAttachName attach to process name "
+ "'%s'",
+ getpid(), attach_name.c_str());
attach_pid = DNBProcessAttachByName(attach_name.c_str(), NULL,
Context().GetUnmaskSignals(), err_str,
sizeof(err_str));
@@ -3961,6 +3970,8 @@
// Wait at most 30 second for attach
struct timespec attach_timeout_abstime;
DNBTimer::OffsetTimeOfDay(&attach_timeout_abstime, 30, 0);
+ DNBLog("[LaunchAttach] START %d vAttach to pid %d", getpid(),
+ pid_attaching_to);
attach_pid = DNBProcessAttach(pid_attaching_to, &attach_timeout_abstime,
false, err_str, sizeof(err_str));
}
@@ -3971,10 +3982,12 @@
if (attach_pid != INVALID_NUB_PROCESS) {
if (m_ctx.ProcessID() != attach_pid)
m_ctx.SetProcessID(attach_pid);
+ DNBLog("Successfully attached to pid %d", attach_pid);
// Send a stop reply packet to indicate we successfully attached!
NotifyThatProcessStopped();
return rnb_success;
} else {
+ DNBLogError("Attach failed");
m_ctx.LaunchStatus().SetError(-1, DNBError::Generic);
if (err_str[0])
m_ctx.LaunchStatus().SetErrorString(err_str);
@@ -4645,10 +4658,14 @@
// Detach from gdb.
rnb_err_t RNBRemote::HandlePacket_D(const char *p) {
if (m_ctx.HasValidProcessID()) {
+ DNBLog("detaching from pid %u due to D packet", m_ctx.ProcessID());
if (DNBProcessDetach(m_ctx.ProcessID()))
SendPacket("OK");
- else
+ else {
+ DNBLog("error while detaching from pid %u due to D packet",
+ m_ctx.ProcessID());
SendPacket("E");
+ }
} else {
SendPacket("E");
}
Index: lldb/tools/debugserver/source/MacOSX/MachTask.mm
===================================================================
--- lldb/tools/debugserver/source/MacOSX/MachTask.mm
+++ lldb/tools/debugserver/source/MacOSX/MachTask.mm
@@ -512,6 +512,7 @@
mach_port_t task_self = mach_task_self();
task_t task = TASK_NULL;
for (uint32_t i = 0; i < num_retries; i++) {
+ DNBLog("[LaunchAttach] (%d) about to task_for_pid(%d)", getpid(), pid);
err = ::task_for_pid(task_self, pid, &task);
if (DNBLogCheckLogBit(LOG_TASK) || err.Fail()) {
@@ -522,13 +523,19 @@
err.AsString() ? err.AsString() : "success");
if (err.Fail()) {
err.SetErrorString(str);
- DNBLogError ("MachTask::TaskPortForProcessID task_for_pid failed: %s", str);
+ DNBLogError(
+ "[LaunchAttach] MachTask::TaskPortForProcessID task_for_pid(%d) "
+ "failed: %s",
+ pid, str);
}
err.LogThreaded(str);
}
- if (err.Success())
+ if (err.Success()) {
+ DNBLog("[LaunchAttach] (%d) successfully task_for_pid(%d)'ed", getpid(),
+ pid);
return task;
+ }
// Sleep a bit and try again
::usleep(usec_interval);
Index: lldb/tools/debugserver/source/MacOSX/MachProcess.mm
===================================================================
--- lldb/tools/debugserver/source/MacOSX/MachProcess.mm
+++ lldb/tools/debugserver/source/MacOSX/MachProcess.mm
@@ -140,8 +140,10 @@
cstr = "<Unknown Bundle ID>";
NSString *description = [options description];
- DNBLog("About to launch process for bundle ID: %s - options:\n%s", cstr,
- [description UTF8String]);
+ DNBLog("[LaunchAttach] START (%d) templated *Board launcher: app lunch "
+ "request for "
+ "'%s' - options:\n%s",
+ getpid(), cstr, [description UTF8String]);
[system_service
openApplication:bundleIDNSStr
options:options
@@ -156,33 +158,36 @@
if (wants_pid) {
pid_in_block =
[system_service pidForApplication:bundleIDNSStr];
- DNBLog(
- "In completion handler, got pid for bundle id, pid: %d.",
- pid_in_block);
- DNBLogThreadedIf(
- LOG_PROCESS,
- "In completion handler, got pid for bundle id, pid: %d.",
- pid_in_block);
- } else
- DNBLogThreadedIf(LOG_PROCESS,
- "In completion handler: success.");
+ DNBLog("[LaunchAttach] In completion handler, got pid for "
+ "bundle id "
+ "'%s', pid: %d.",
+ cstr, pid_in_block);
+ } else {
+ DNBLog("[LaunchAttach] In completion handler, launch was "
+ "successful, "
+ "debugserver did not ask for the pid");
+ }
} else {
const char *error_str =
[(NSString *)[bks_error localizedDescription] UTF8String];
if (error_str) {
open_app_error_string = error_str;
- DNBLogError("In app launch attempt, got error "
- "localizedDescription '%s'.", error_str);
+ DNBLogError(
+ "[LaunchAttach] END (%d) In app launch attempt, got error "
+ "localizedDescription '%s'.",
+ getpid(), error_str);
const char *obj_desc =
[NSString stringWithFormat:@"%@", bks_error].UTF8String;
- DNBLogError("In app launch attempt, got error "
- "NSError object description: '%s'.",
- obj_desc);
+ DNBLogError(
+ "[LaunchAttach] END (%d) In app launch attempt, got error "
+ "NSError object description: '%s'.",
+ getpid(), obj_desc);
}
- DNBLogThreadedIf(LOG_PROCESS, "In completion handler for send "
- "event, got error \"%s\"(%ld).",
+ DNBLogThreadedIf(LOG_PROCESS,
+ "In completion handler for send "
+ "event, got error \"%s\"(%ld).",
error_str ? error_str : "<unknown error>",
- open_app_error);
+ (long)open_app_error);
}
[system_service release];
@@ -200,15 +205,23 @@
dispatch_release(semaphore);
+ DNBLog("[LaunchAttach] END (%d) templated *Board launcher finished app lunch "
+ "request for "
+ "'%s'",
+ getpid(), cstr);
+
if (!success) {
- DNBLogError("timed out trying to send openApplication to %s.", cstr);
+ DNBLogError("[LaunchAttach] END (%d) timed out trying to send "
+ "openApplication to %s.",
+ getpid(), cstr);
error.SetError(OPEN_APPLICATION_TIMEOUT_ERROR, DNBError::Generic);
error.SetErrorString("timed out trying to launch app");
} else if (open_app_error != no_error_enum_value) {
error_function(open_app_error, open_app_error_string, error);
- DNBLogError("unable to launch the application with CFBundleIdentifier '%s' "
- "bks_error = %u",
- cstr, open_app_error);
+ DNBLogError("[LaunchAttach] END (%d) unable to launch the application with "
+ "CFBundleIdentifier '%s' "
+ "bks_error = %ld",
+ getpid(), cstr, (long)open_app_error);
success = false;
} else if (wants_pid) {
*return_pid = pid_in_block;
@@ -1428,7 +1441,7 @@
DNBLogThreadedIf(LOG_PROCESS, "MachProcess::Kill() DoSIGSTOP() state = %s",
DNBStateAsString(state));
errno = 0;
- DNBLog("Sending ptrace PT_KILL to terminate inferior process.");
+ DNBLog("Sending ptrace PT_KILL to terminate inferior process pid %d.", m_pid);
::ptrace(PT_KILL, m_pid, 0, 0);
DNBError err;
err.SetErrorToErrno();
@@ -2623,15 +2636,26 @@
::snprintf(err_str, err_len, "%s",
err_cstr ? err_cstr : "unable to start the exception thread");
DNBLogThreadedIf(LOG_PROCESS, "error: failed to attach to pid %d", pid);
- DNBLogError ("MachProcess::AttachForDebug failed to start exception thread: %s", err_str);
+ DNBLogError(
+ "[LaunchAttach] END (%d) MachProcess::AttachForDebug failed to start "
+ "exception thread attaching to pid %i: %s",
+ getpid(), pid, err_str);
m_pid = INVALID_NUB_PROCESS;
return INVALID_NUB_PROCESS;
}
+ DNBLog("[LaunchAttach] (%d) About to ptrace(PT_ATTACHEXC, %d)...", getpid(),
+ pid);
errno = 0;
- if (::ptrace(PT_ATTACHEXC, pid, 0, 0)) {
- err.SetError(errno);
- DNBLogError ("MachProcess::AttachForDebug failed to ptrace(PT_ATTACHEXC): %s", err.AsString());
+ int ptrace_result = ::ptrace(PT_ATTACHEXC, pid, 0, 0);
+ int ptrace_errno = errno;
+ DNBLog("[LaunchAttach] (%d) Completed ptrace(PT_ATTACHEXC, %d) == %d",
+ getpid(), pid, ptrace_result);
+ if (ptrace_result != 0) {
+ err.SetError(ptrace_errno);
+ DNBLogError("MachProcess::AttachForDebug failed to ptrace(PT_ATTACHEXC) "
+ "pid %i: %s",
+ pid, err.AsString());
} else {
err.Clear();
}
@@ -2642,11 +2666,16 @@
// status
// to stopped.
::usleep(250000);
+ DNBLog("[LaunchAttach] (%d) Done napping after ptrace(PT_ATTACHEXC)'ing",
+ getpid());
DNBLogThreadedIf(LOG_PROCESS, "successfully attached to pid %d", pid);
return m_pid;
} else {
::snprintf(err_str, err_len, "%s", err.AsString());
- DNBLogError ("MachProcess::AttachForDebug error: failed to attach to pid %d", pid);
+ DNBLogError(
+ "[LaunchAttach] (%d) MachProcess::AttachForDebug error: failed to "
+ "attach to pid %d",
+ getpid(), pid);
struct kinfo_proc kinfo;
int mib[] = {CTL_KERN, KERN_PROC, KERN_PROC_PID, pid};
@@ -2654,7 +2683,10 @@
if (sysctl(mib, sizeof(mib) / sizeof(mib[0]), &kinfo, &len, NULL, 0) == 0 && len > 0) {
if (kinfo.kp_proc.p_flag & P_TRACED) {
::snprintf(err_str, err_len, "%s - process %d is already being debugged", err.AsString(), pid);
- DNBLogError ("MachProcess::AttachForDebug pid %d is already being debugged", pid);
+ DNBLogError(
+ "[LaunchAttach] (%d) MachProcess::AttachForDebug pid %d is "
+ "already being debugged",
+ getpid(), pid);
}
}
}
@@ -2815,6 +2847,9 @@
NSString *bundleIDNSStr = (NSString *)bundleIDCFStr;
+ DNBLog("[LaunchAttach] START (%d) requesting FBS launch of app with bundle "
+ "ID '%s'",
+ getpid(), bundleIDStr.c_str());
[system_service openApplication:bundleIDNSStr
options:options
clientPort:client_port
@@ -2893,6 +2928,9 @@
NSString *bundleIDNSStr = (NSString *)bundleIDCFStr;
+ DNBLog("[LaunchAttach] START (%d) requesting BKS launch of app with bundle "
+ "ID '%s'",
+ getpid(), bundleIDStr.c_str());
[system_service openApplication:bundleIDNSStr
options:options
clientPort:client_port
@@ -2923,7 +2961,7 @@
std::string empty_str;
SetBKSError(attach_error_code, empty_str, attach_err);
DNBLogError("unable to launch the application with CFBundleIdentifier "
- "'%s' bks_error = %ld",
+ "'%s' bks_error = %d",
bundleIDStr.c_str(), attach_error_code);
}
dispatch_release(semaphore);
@@ -2945,6 +2983,10 @@
"SBSApplicationLaunchWaitForDebugger )",
bundleIDStr.c_str(), stdout_err, stdout_err);
+ DNBLog("[LaunchAttach] START (%d) requesting SpringBoard launch of app "
+ "with bundle "
+ "ID '%s'",
+ getpid(), bundleIDStr.c_str());
sbs_error = SBSLaunchApplicationForDebugging(
bundleIDCFStr,
(CFURLRef)NULL, // openURL
@@ -3105,7 +3147,7 @@
m_flags |= (eMachProcessFlagsUsingFBS | eMachProcessFlagsBoardCalculated);
if (BoardServiceLaunchForDebug(app_bundle_path.c_str(), argv, envp,
no_stdio, disable_aslr, event_data,
- launch_err) != 0)
+ unmask_signals, launch_err) != 0)
return m_pid; // A successful SBLaunchForDebug() returns and assigns a
// non-zero m_pid.
else
@@ -3121,7 +3163,7 @@
m_flags |= (eMachProcessFlagsUsingBKS | eMachProcessFlagsBoardCalculated);
if (BoardServiceLaunchForDebug(app_bundle_path.c_str(), argv, envp,
no_stdio, disable_aslr, event_data,
- launch_err) != 0)
+ unmask_signals, launch_err) != 0)
return m_pid; // A successful SBLaunchForDebug() returns and assigns a
// non-zero m_pid.
else
@@ -3148,7 +3190,7 @@
if (app_ext) {
std::string app_bundle_path(path, app_ext + strlen(".app"));
if (SBLaunchForDebug(app_bundle_path.c_str(), argv, envp, no_stdio,
- disable_aslr, launch_err) != 0)
+ disable_aslr, unmask_signals, launch_err) != 0)
return m_pid; // A successful SBLaunchForDebug() returns and assigns a
// non-zero m_pid.
else
@@ -3200,14 +3242,19 @@
SetState(eStateAttaching);
errno = 0;
+ DNBLog("[LaunchAttach] (%d) About to ptrace(PT_ATTACHEXC, %d)...",
+ getpid(), m_pid);
int err = ::ptrace(PT_ATTACHEXC, m_pid, 0, 0);
+ int ptrace_errno = errno;
+ DNBLog("[LaunchAttach] (%d) Completed ptrace(PT_ATTACHEXC, %d) == %d",
+ getpid(), m_pid, err);
if (err == 0) {
m_flags |= eMachProcessFlagsAttached;
DNBLogThreadedIf(LOG_PROCESS, "successfully spawned pid %d", m_pid);
launch_err.Clear();
} else {
SetState(eStateExited);
- DNBError ptrace_err(errno, DNBError::POSIX);
+ DNBError ptrace_err(ptrace_errno, DNBError::POSIX);
DNBLogThreadedIf(LOG_PROCESS, "error: failed to attach to spawned pid "
"%d (err = %i, errno = %i (%s))",
m_pid, err, ptrace_err.Status(),
@@ -3577,7 +3624,11 @@
StartSTDIOThread();
SetState(eStateAttaching);
+ DNBLog("[LaunchAttach] (%d) About to ptrace(PT_ATTACHEXC, %d)...", getpid(),
+ m_pid);
int err = ::ptrace(PT_ATTACHEXC, m_pid, 0, 0);
+ DNBLog("[LaunchAttach] (%d) Completed ptrace(PT_ATTACHEXC, %d) == %d",
+ getpid(), m_pid, err);
if (err == 0) {
m_flags |= eMachProcessFlagsAttached;
DNBLogThreadedIf(LOG_PROCESS, "successfully attached to pid %d", m_pid);
@@ -3779,8 +3830,11 @@
if (launch_err.Fail()) {
if (launch_err.AsString() == NULL)
launch_err.SetErrorString("unable to start the exception thread");
- DNBLog("Could not get inferior's Mach exception port, sending ptrace "
- "PT_KILL and exiting.");
+ DNBLog("[LaunchAttach] END (%d) Could not get inferior's Mach exception "
+ "port, "
+ "sending ptrace "
+ "PT_KILL to pid %i and exiting.",
+ getpid(), m_pid);
::ptrace(PT_KILL, m_pid, 0, 0);
m_pid = INVALID_NUB_PROCESS;
return INVALID_NUB_PROCESS;
@@ -3788,13 +3842,18 @@
StartSTDIOThread();
SetState(eStateAttaching);
+ DNBLog("[LaunchAttach] (%d) About to ptrace(PT_ATTACHEXC, %d)...", getpid(),
+ m_pid);
int err = ::ptrace(PT_ATTACHEXC, m_pid, 0, 0);
+ DNBLog("[LaunchAttach] (%d) Completed ptrace(PT_ATTACHEXC, %d) == %d",
+ getpid(), m_pid, err);
if (err == 0) {
m_flags |= eMachProcessFlagsAttached;
- DNBLogThreadedIf(LOG_PROCESS, "successfully attached to pid %d", m_pid);
+ DNBLog("[LaunchAttach] successfully attached to pid %d", m_pid);
} else {
SetState(eStateExited);
- DNBLogThreadedIf(LOG_PROCESS, "error: failed to attach to pid %d", m_pid);
+ DNBLog("[LaunchAttach] END (%d) error: failed to attach to pid %d",
+ getpid(), m_pid);
}
}
return m_pid;
_______________________________________________
lldb-commits mailing list
lldb-commits@lists.llvm.org
https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits
