Skip to content

Add unconditional logging to debugserver for launch/attach processes #2333

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Jan 14, 2021
Merged

Add unconditional logging to debugserver for launch/attach processes #2333

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
139 changes: 99 additions & 40 deletions lldb/tools/debugserver/source/MacOSX/MachProcess.mm
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -140,8 +140,10 @@ static bool CallBoardSystemServiceOpenApplication(NSString *bundleIDNSStr,
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
Expand All @@ -156,33 +158,36 @@ static bool CallBoardSystemServiceOpenApplication(NSString *bundleIDNSStr,
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];
Expand All @@ -200,15 +205,23 @@ static bool CallBoardSystemServiceOpenApplication(NSString *bundleIDNSStr,

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;
Expand Down Expand Up @@ -1428,7 +1441,7 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,
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();
Expand Down Expand Up @@ -2623,15 +2636,26 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,
::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();
}
Expand All @@ -2642,19 +2666,27 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,
// 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};
size_t len = sizeof(struct kinfo_proc);
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);
}
}
}
Expand Down Expand Up @@ -2815,6 +2847,9 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,

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
Expand Down Expand Up @@ -2893,6 +2928,9 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,

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
Expand Down Expand Up @@ -2923,7 +2961,7 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,
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);
Expand All @@ -2945,6 +2983,10 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,
"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
Expand Down Expand Up @@ -3105,7 +3147,7 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,
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
Expand All @@ -3121,7 +3163,7 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,
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
Expand All @@ -3148,7 +3190,7 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,
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
Expand Down Expand Up @@ -3200,14 +3242,19 @@ static bool FBSAddEventDataToOptions(NSMutableDictionary *options,

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(),
Expand Down Expand Up @@ -3577,7 +3624,11 @@ static CFStringRef CopyBundleIDForPath(const char *app_bundle_path,

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);
Expand Down Expand Up @@ -3779,22 +3830,30 @@ static CFStringRef CopyBundleIDForPath(const char *app_bundle_path,
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;
}

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;
Expand Down
11 changes: 9 additions & 2 deletions lldb/tools/debugserver/source/MacOSX/MachTask.mm
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -512,6 +512,7 @@ static void get_threads_profile_data(DNBProfileDataScanType scanType,
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()) {
Expand All @@ -522,13 +523,19 @@ static void get_threads_profile_data(DNBProfileDataScanType scanType,
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);
Expand Down
Loading