commit 7d015c886a3fc985ab767de01811d1591f0ac86a Author: Steven Murdoch Steven.Murdoch@cl.cam.ac.uk Date: Thu Aug 18 18:41:23 2011 +0100

Complete logging of output from port forwarding helper --- src/common/util.c | 139 +++++++++++++++++++++++++++++++++++++------------- src/common/util.h | 6 ++- src/test/test_util.c | 4 +- 3 files changed, 110 insertions(+), 39 deletions(-)

diff --git a/src/common/util.c b/src/common/util.c index 5a5f3b5..3769d06 100644 --- a/src/common/util.c +++ b/src/common/util.c @@ -3070,7 +3070,7 @@ tor_spawn_background(const char *const filename, const char **argv) // TODO: Close hProcess and hThread in process_handle.pid? process_handle.stdout_pipe = stdout_pipe_read; process_handle.stderr_pipe = stderr_pipe_read; - process_handle.status = 0; + process_handle.status = 1; }

// TODO: Close pipes on exit @@ -3248,20 +3248,36 @@ tor_spawn_background(const char *const filename, const char **argv) needs to know about the pid in order to reap it later */ }

- process_handle.status = 0; + process_handle.status = 1; process_handle.pid = pid; + /* Set stdout/stderr pipes to be non-blocking */ + fcntl(process_handle.stdout_pipe, F_SETFL, O_NONBLOCK); + fcntl(process_handle.stderr_pipe, F_SETFL, O_NONBLOCK); + /* Open the buffered IO streams */ + process_handle.stdout_handle = fdopen(process_handle.stdout_pipe, "r"); + process_handle.stderr_handle = fdopen(process_handle.stderr_pipe, "r"); + return process_handle; #endif // MS_WINDOWS }

int -tor_get_exit_code(const process_handle_t process_handle) +tor_get_exit_code(const process_handle_t process_handle, int block) { #ifdef MS_WINDOWS DWORD exit_code; BOOL retval; - WaitForSingleObject(process_handle.pid.hProcess, INFINITE); - retval = GetExitCodeProcess(process_handle.pid.hProcess, &exit_code); + if (block) { + exit_code = WaitForSingleObject(process_handle.pid.hProcess, INFINITE); + retval = GetExitCodeProcess(process_handle.pid.hProcess, &exit_code); + } else { + exit_code = WaitForSingleObject(process_handle.pid.hProcess, 0); + if (WAIT_TIMEOUT == exit_code) { + // Process has not exited + return -2; + } + retval = GetExitCodeProcess(process_handle.pid.hProcess, &exit_code); + }

if (!retval) { log_warn(LD_GENERAL, "GetExitCodeProcess() failed: %s", @@ -3371,6 +3387,55 @@ tor_read_all_from_process_stderr(const process_handle_t process_handle, #endif }

+#ifdef MS_WINDOWS +static int +log_from_handle(HANDLE *pipe, int severity) +{ + char buf[256]; + int pos; + int start, cur, next; + + pos = tor_read_all_handle(pipe, buf, sizeof(buf) - 1, NULL); + if (pos < 0) { + // Error + log_warn(LD_GENERAL, "Failed to read data from subprocess"); + return -1; + } + + if (0 == pos) { + // There's nothing to read (process is busy or has exited) + log_debug(LD_GENERAL, "Subprocess had nothing to say"); + return 0; + } + + // End with a null even if there isn't a \r\n at the end + // TODO: What if this is a partial line? + buf[pos] = '\0'; + log_debug(LD_GENERAL, "Subprocess had %d bytes to say", pos); + + next = 0; // Start of the next line + while (next < pos) { + start = next; // Look for the end of this line + for (cur=start; cur<pos; cur++) { + if ('\r' == buf[cur]) { + buf[cur] = '\0'; + next = cur + 1; + if ((cur + 1) < pos && buf[cur+1] < pos) { + buf[cur + 1] = '\0'; + next = cur + 2; + } + // Line starts at start and ends with a null (was \r\n) + break; + } + // Line starts at start and ends at the end of a string + // but we already added a null in earlier + } + log_fn(severity, LD_GENERAL, "Port forwarding helper says: %s", buf+start); + } + return pos; +} + +#else /** Read from stream, and send lines to log at the specified log level. * Returns 1 if stream is closed normally, -1 if there is a error reading, and * 0 otherwise. Handles lines from tor-fw-helper and @@ -3446,28 +3511,23 @@ log_from_pipe(FILE *stream, int severity, const char *executable, /* We should never get here */ return -1; } +#endif

void tor_check_port_forwarding(const char *filename, int dir_port, int or_port, time_t now) { -#ifdef MS_WINDOWS - (void) filename; (void) dir_port; (void) or_port; (void) now; - (void) tor_spawn_background; - (void) log_from_pipe; - log_warn(LD_GENERAL, "Sorry, port forwarding is not yet supported " - "on windows."); -#else /* When fw-helper succeeds, how long do we wait until running it again */ #define TIME_TO_EXEC_FWHELPER_SUCCESS 300 /* When fw-helper fails, how long do we wait until running it again */ #define TIME_TO_EXEC_FWHELPER_FAIL 60

- // XXX: remove - static int child_pid = -1; - static process_handle_t child_handle = {0, 0, 0, 0}; - static FILE *stdout_read = NULL; - static FILE *stderr_read = NULL; +#ifdef MS_WINDOWS + static process_handle_t child_handle = {0, NULL, NULL, {NULL}}; +#else + static process_handle_t child_handle; +#endif + static time_t time_to_run_helper = 0; int stdout_status, stderr_status, retval; const char *argv[10]; @@ -3492,37 +3552,40 @@ tor_check_port_forwarding(const char *filename, int dir_port, int or_port, argv[9] = NULL;

/* Start the child, if it is not already running */ - if (-1 == child_pid && - time_to_run_helper < now) { - int fd_out=-1, fd_err=-1; - + if (child_handle.status <= 0 && time_to_run_helper < now) { /* Assume tor-fw-helper will succeed, start it later*/ time_to_run_helper = now + TIME_TO_EXEC_FWHELPER_SUCCESS;

child_handle = tor_spawn_background(filename, argv); - if (child_pid < 0) { + if (child_handle.status < 0) { log_warn(LD_GENERAL, "Failed to start port forwarding helper %s", filename); - child_pid = -1; return; } - /* Set stdout/stderr pipes to be non-blocking */ - fcntl(fd_out, F_SETFL, O_NONBLOCK); - fcntl(fd_err, F_SETFL, O_NONBLOCK); - /* Open the buffered IO streams */ - stdout_read = fdopen(fd_out, "r"); - stderr_read = fdopen(fd_err, "r"); - +#ifdef MS_WINDOWS + log_info(LD_GENERAL, + "Started port forwarding helper (%s)", filename); +#else log_info(LD_GENERAL, "Started port forwarding helper (%s) with pid %d", filename, child_pid); +#endif }

/* If child is running, read from its stdout and stderr) */ - if (child_pid > 0) { + if (child_handle.status > 0) { /* Read from stdout/stderr and log result */ retval = 0; - stdout_status = log_from_pipe(stdout_read, LOG_INFO, filename, &retval); - stderr_status = log_from_pipe(stderr_read, LOG_WARN, filename, &retval); +#ifdef MS_WINDOWS + stdout_status = log_from_handle(child_handle.stdout_pipe, LOG_INFO); + stderr_status = log_from_handle(child_handle.stderr_pipe, LOG_WARN); + // If we got this far (on Windows), the process started + retval = 0; +#else + stdout_status = log_from_pipe(child_handle.stdout_handle, + LOG_INFO, filename, &retval); + stderr_status = log_from_pipe(child_handle.stderr_handle, + LOG_WARN, filename, &retval); +#endif if (retval) { /* There was a problem in the child process */ time_to_run_helper = now + TIME_TO_EXEC_FWHELPER_FAIL; @@ -3532,9 +3595,16 @@ tor_check_port_forwarding(const char *filename, int dir_port, int or_port, if (-1 == stdout_status || -1 == stderr_status) /* There was a failure */ retval = -1; +#ifdef MS_WINDOWS + else if (tor_get_exit_code(child_handle, 0) >= 0) { + /* process has exited */ + retval = 1; + } +#else else if (1 == stdout_status || 1 == stderr_status) /* stdout or stderr was closed */ retval = 1; +#endif else /* Both are fine */ retval = 0; @@ -3549,9 +3619,8 @@ tor_check_port_forwarding(const char *filename, int dir_port, int or_port,

/* TODO: The child might not actually be finished (maybe it failed or closed stdout/stderr), so maybe we shouldn't start another? */ - child_pid = -1; + child_handle.status = -1; } } -#endif }

diff --git a/src/common/util.h b/src/common/util.h index 2efe557..40fe305 100644 --- a/src/common/util.h +++ b/src/common/util.h @@ -349,7 +349,7 @@ HANDLE load_windows_system_library(const TCHAR *library_name); /* Prototypes for private functions only used by util.c (and unit tests) */

typedef struct process_handle_s { - int status; + int status; // 0: not running; 1: running; -1: error #ifdef MS_WINDOWS HANDLE stdout_pipe; HANDLE stderr_pipe; @@ -357,13 +357,15 @@ typedef struct process_handle_s { #else int stdout_pipe; int stderr_pipe; + FILE *stdout_handle; + FILE *stderr_handle; int pid; #endif // MS_WINDOWS } process_handle_t;

process_handle_t tor_spawn_background(const char *const filename, const char **argv); -int tor_get_exit_code(const process_handle_t pid); +int tor_get_exit_code(const process_handle_t pid, int block); ssize_t tor_read_all_handle(HANDLE h, char *buf, size_t count, HANDLE hProcess); ssize_t tor_read_all_from_process_stdout(const process_handle_t process_handle, char *buf, size_t count); diff --git a/src/test/test_util.c b/src/test/test_util.c index 071fd04..6f87560 100644 --- a/src/test/test_util.c +++ b/src/test/test_util.c @@ -1408,7 +1408,7 @@ run_util_spawn_background(const char *argv[], const char *expected_out, tt_int_op(pos, ==, strlen(expected_out));

/* Check it terminated correctly */ - retval = tor_get_exit_code(process_handle); + retval = tor_get_exit_code(process_handle, 1); tt_int_op(retval, ==, expected_exit); // TODO: Make test-child exit with something other than 0

@@ -1529,7 +1529,7 @@ test_util_spawn_background_partial_read(void *ptr) #endif

/* Check it terminated correctly */ - retval = tor_get_exit_code(process_handle); + retval = tor_get_exit_code(process_handle, 1); tt_int_op(retval, ==, expected_exit); // TODO: Make test-child exit with something other than 0