525090 - Need child process PID's logged to file

Status: RESOLVED FIXED

(Core :: IPC, defect)

Description

[Jonathan Griffin (:jgriffin)]

In order to reliably detect orphan child processes at the end of a mochitest (or other) test run, we need the PID's of child processes launched to be written to a log file, possibly specified by some environment variable, similar to the way we use XPCOM_MEM_BLOAT_LOG to specify the location of the leak log file.

We can then scan this list of PID's after firefox shuts down at the end of a run, and add a TEXT-UNEXPECTED-FAIL if any remain alive.

I can help with this if you tell me where in the code this should live.

Comment 1

[Benjamin Smedberg]

cjones knows!

Comment 2

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Could we get away with printing a special message to stdout with this information rather than appending to a file?  It's useful information to log in general, not only just for the test runs.

We could do either the stdout or logfile approach pretty easily in C++/libxul, at the point where we launch the child.  For "maximum reliability", we'd probably want to log this information in ipc/chromium/src/base/process_util_win.cc and ipc/chromium/src/base/process_util_linux.cc, *just* after that code gets a valid child pid/HANDLE from the OS.

Comment 3

[Jonathan Griffin (:jgriffin)]

Thanks Chris.

Comment 4

[Jonathan Griffin (:jgriffin)]

Attachment: patch

Prints the PID of launched processes on linux and win32 to stdout.

Comment 5

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Comment on attachment 409386 [details] [diff] [review]
patch

>diff --git a/ipc/chromium/src/base/process_util_linux.cc b/ipc/chromium/src/base/process_util_linux.cc
>--- a/ipc/chromium/src/base/process_util_linux.cc
>+++ b/ipc/chromium/src/base/process_util_linux.cc
>@@ -59,16 +59,17 @@ bool LaunchApp(const std::vector<std::st
> "vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv\n"
> "---->   FAILED TO exec() CHILD PROCESS   <---\n"
> "---->     path: %s\n"
> "^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n",
>             argv_cstr[0]);
> #endif
>     exit(127);
>   } else {
>+    printf("==> Launching child process with PID %d\n", pid);
>     if (wait)
>       HANDLE_EINTR(waitpid(pid, 0, 0));
> 
>     if (process_handle)
>       *process_handle = pid;
>   }
> 
>   return true;
>diff --git a/ipc/chromium/src/base/process_util_win.cc b/ipc/chromium/src/base/process_util_win.cc
>--- a/ipc/chromium/src/base/process_util_win.cc
>+++ b/ipc/chromium/src/base/process_util_win.cc
>@@ -157,16 +157,19 @@ bool LaunchApp(const std::wstring& cmdli
>   startup_info.wShowWindow = start_hidden ? SW_HIDE : SW_SHOW;
>   PROCESS_INFORMATION process_info;
>   if (!CreateProcess(NULL,
>                      const_cast<wchar_t*>(cmdline.c_str()), NULL, NULL,
>                      FALSE, 0, NULL, NULL,
>                      &startup_info, &process_info))
>     return false;
> 
>+  printf("==> Launching child process with PID %d\n",
>+          process_info.dwProcessId);
>+
>   // Handles must be closed or they will leak
>   CloseHandle(process_info.hThread);
> 
>   if (wait)
>     WaitForSingleObject(process_info.hProcess, INFINITE);
> 
>   // If the caller wants the process handle, we won't close it.
>   if (process_handle) {

Looks good to me.  It might be worthwhile to additionally log the PID of the process *launching* the subprocess, so we can track the process tree and assess more specific blame.  E.g. "==> %d launching child process %d".  There's a utility method in ipc/chromium/src/base/process_utils.h for getting the current process's PID.

Comment 6

[Jonathan Griffin (:jgriffin)]

Pushed, with cjones suggested change, as http://hg.mozilla.org/projects/electrolysis/rev/777af746b294

Comment 7

[(not currently active) Ted Mielczarek]

I'm not sure that I like the non-DEBUG console spew that this adds. In general, I don't think our app should be spitting random information like this to stdout except in debug builds.

Comment 8

[(not currently active) Ted Mielczarek]

I would like this to output to a logfile if an environment variable is specified (MOZ_LOG_PROCESSES?), and only to stdout ifdef DEBUG.

Comment 9

[Benjamin Smedberg]

Attachment: Log to a file based on the environment, rev. 1

Comment 10

[Benjamin Smedberg]

http://hg.mozilla.org/projects/electrolysis/rev/ee79c580c482