From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from smtp49.i.mail.ru (smtp49.i.mail.ru [94.100.177.109]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dev.tarantool.org (Postfix) with ESMTPS id D6FA34696C8 for ; Fri, 10 Apr 2020 05:51:14 +0300 (MSK) From: Alexander Turenko Date: Fri, 10 Apr 2020 05:50:44 +0300 Message-Id: In-Reply-To: References: MIME-Version: 1.0 Content-Transfer-Encoding: 8bit Subject: [Tarantool-patches] [PATCH 06/13] popen: decouple logger fd from stderr List-Id: Tarantool development patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Cyrill Gorcunov Cc: tarantool-patches@dev.tarantool.org The default logger configuration writes logs to stderr. Popen implementation holds a logger fd until execve() to be able to write debug entries or information about a failure from a child. However when popen flags requires to close stderr in the child, the logger fd becomes closed: logging will fail. Another problem appears when a user want to capture stderr and tarantool's log level is set to debug (7). Since the logger uses stderr and it is fed to the parent using a pipe, the logger output will not shown on the 'real' stderr, but will be captured together with child's program debugging output. This commit duplicates a logger file descriptor that allows to close or redirect child's stderr without described side effects. See also 86ec3a5c4792ea1bba9f644da1e8f301314c8d29 ('popen: add logging in child process'). Areas for improvements: * Copy logger fd at module initialization time instead of copying of each popen call. Alternatives: * Extend logger to allow to accumulate log entries in a buffer. Flush the buffer from the parent process. (It is possible since vfork does not split a virtual memory space). Part of #4031 --- src/lib/core/popen.c | 124 +++++++++++++++++++++++++++++++++++++++---- 1 file changed, 115 insertions(+), 9 deletions(-) diff --git a/src/lib/core/popen.c b/src/lib/core/popen.c index 9d4e6ef3a..62920e0c8 100644 --- a/src/lib/core/popen.c +++ b/src/lib/core/popen.c @@ -74,6 +74,59 @@ popen_unregister(struct popen_handle *handle) mh_i32ptr_remove(popen_pids_map, &node, NULL); } +/** + * Duplicate a file descriptor, but not to std{in,out,err}. + * + * Return a new fd at success, otherwise return -1 and set a diag. + */ +static int +dup_not_std_streams(int fd) +{ + int res = -1; + int save_errno = 0; + + /* + * We will call dup() in a loop until it will return + * fd > STDERR_FILENO. The array `discarded_fds` stores + * intermediate fds to close them after all dup() calls. + */ + static_assert(STDERR_FILENO + 1 == 3, + "Unexpected STDERR_FILENO constant"); + int discarded_fds[STDERR_FILENO + 1] = {-1, -1, -1}; + + for (size_t i = 0; i < lengthof(discarded_fds) + 1; ++i) { + int new_fd = dup(fd); + if (new_fd < 0) { + save_errno = errno; + break; + } + + /* Found wanted fd. */ + if (new_fd > STDERR_FILENO) { + res = new_fd; + break; + } + + /* Save to close then. */ + assert(i < lengthof(discarded_fds)); + discarded_fds[i] = new_fd; + } + + /* Close all intermediate fds (if any). */ + for (size_t i = 0; i < lengthof(discarded_fds); ++i) + if (discarded_fds[i] >= 0) + close(discarded_fds[i]); + + /* Report an error if it occurs. */ + if (res < 0) { + errno = save_errno; + diag_set(SystemError, "Unable to duplicate an fd %d", fd); + return -1; + } + + return res; +} + /** * Allocate new popen hanldle with flags specified. */ @@ -746,9 +799,34 @@ popen_new(struct popen_opts *opts) * plus dev/null variants and logfd */ int skip_fds[POPEN_FLAG_FD_STDEND_BIT * 2 + 2 + 1]; - int log_fd = log_get_fd(); size_t nr_skip_fds = 0; + /* + * We must decouple log file descriptor from stderr in order to + * close or redirect stderr, but keep logging as is until + * execve() call. + * + * The new file descriptor should not have the same number as + * stdin, stdout or stderr. + * + * NB: It is better to acquire it from the parent to catch + * possible error sooner and don't ever call vfork() if we + * reached a file descriptor limit. + */ + int old_log_fd = log_get_fd(); + int log_fd = -1; + if (old_log_fd >= 0) { + log_fd = dup_not_std_streams(old_log_fd); + if (log_fd < 0) + return NULL; + if (fcntl(log_fd, F_SETFL, O_CLOEXEC) != 0) { + diag_set(SystemError, + "Unable to set O_CLOEXEC on temporary logfd"); + close(log_fd); + return NULL; + } + } + /* * A caller must preserve space for this. */ @@ -771,8 +849,11 @@ popen_new(struct popen_opts *opts) "Popen flags do not match stdX"); handle = handle_new(opts); - if (!handle) + if (!handle) { + if (log_fd >= 0) + close(log_fd); return NULL; + } if (log_fd >= 0) skip_fds[nr_skip_fds++] = log_fd; @@ -839,6 +920,20 @@ popen_new(struct popen_opts *opts) * do anything special. */ + /* + * Replace the logger fd to its duplicate. It + * should be done before we'll close inherited + * fds: old logger fd may be stderr and stderr may + * be subject to close. + * + * We should also do it before a first call to a + * say_*() function, because otherwise a user may + * capture our debug logs as stderr of the child + * process. + */ + if (log_fd >= 0) + log_set_fd(log_fd); + /* * Also don't forget to drop signal handlers * to default inside a child process since we're @@ -944,19 +1039,21 @@ popen_new(struct popen_opts *opts) goto exit_child; } - if (log_fd >= 0) { - if (close(log_fd)) { - say_error("child: can't close logfd %d", - log_fd); - goto exit_child; - } - } + /* + * Return the logger back, because we're in the + * same virtual memory address space as the + * parent. + */ + if (log_fd >= 0) + log_set_fd(old_log_fd); if (opts->flags & POPEN_FLAG_SHELL) execve(_PATH_BSHELL, opts->argv, envp); else execve(opts->argv[0], opts->argv, envp); exit_child: + if (log_fd >= 0) + log_set_fd(old_log_fd); _exit(errno); unreachable(); } @@ -987,6 +1084,13 @@ exit_child: } } + /* Close the temporary logger fd. */ + if (log_fd >= 0 && close(log_fd) != 0) { + diag_set(SystemError, "Can't close temporary logfd %d", log_fd); + log_fd = -1; + goto out_err; + } + /* * Link it into global list for force * cleanup on exit. Note we use this @@ -1018,6 +1122,8 @@ out_err: if (pfd[i][1] != -1) close(pfd[i][1]); } + if (log_fd >= 0) + close(log_fd); errno = saved_errno; return NULL; } -- 2.25.0