Tarantool development patches archive
 help / color / mirror / Atom feed
From: Alexander Turenko <alexander.turenko@tarantool.org>
To: Cyrill Gorcunov <gorcunov@gmail.com>
Cc: tarantool-patches@dev.tarantool.org
Subject: [Tarantool-patches] [PATCH 06/13] popen: decouple logger fd from stderr
Date: Fri, 10 Apr 2020 05:50:44 +0300	[thread overview]
Message-ID: <a1b0d4e4dc4ecad001e0cb0e778e36342303fde3.1586486220.git.alexander.turenko@tarantool.org> (raw)
In-Reply-To: <cover.1586486219.git.alexander.turenko@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

  parent reply	other threads:[~2020-04-10  2:51 UTC|newest]

Thread overview: 36+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2020-04-10  2:50 [Tarantool-patches] [PATCH 00/13] Popen Lua API: preliminary patches Alexander Turenko
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 01/13] popen: require popen handle to be non-NULL Alexander Turenko
2020-04-10  7:16   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 02/13] popen: remove retval from popen_state() Alexander Turenko
2020-04-10  7:17   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 03/13] popen: add missed diag_set in popen_signal/delete Alexander Turenko
2020-04-10  7:23   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 04/13] popen: add logging of fds closed in a child Alexander Turenko
2020-04-10  7:46   ` Cyrill Gorcunov
2020-04-10 12:19     ` Alexander Turenko
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 05/13] say: allow to set a logger file descriptor Alexander Turenko
2020-04-10  8:33   ` Cyrill Gorcunov
2020-04-10 12:19     ` Alexander Turenko
2020-04-10  2:50 ` Alexander Turenko [this message]
2020-04-10  9:18   ` [Tarantool-patches] [PATCH 06/13] popen: decouple logger fd from stderr Cyrill Gorcunov
2020-04-10 12:20     ` Alexander Turenko
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 07/13] popen: add const qualifier to popen_write_timeout Alexander Turenko
2020-04-10  8:04   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 08/13] popen: unblock popen_read_timeout at a first byte Alexander Turenko
2020-04-10  8:10   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 09/13] popen: remove redundant fd check before perform IO Alexander Turenko
2020-04-10  8:18   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 10/13] popen: add missed diag_set() in popen IO functions Alexander Turenko
2020-04-10  8:28   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 11/13] coio: fix obsoleted comment in coio_write_timeout Alexander Turenko
2020-04-10  8:28   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 12/13] coio: add *_noxc read / write functions Alexander Turenko
2020-04-10  8:05   ` Konstantin Osipov
2020-04-10  8:17     ` Cyrill Gorcunov
2020-04-10 11:57     ` Alexander Turenko
2020-04-12 12:51     ` Alexander Turenko
2020-04-10  8:29   ` Cyrill Gorcunov
2020-04-10  2:50 ` [Tarantool-patches] [PATCH 13/13] popen: use of exception safe functions for IO Alexander Turenko
2020-04-10 11:50   ` Cyrill Gorcunov
2020-04-10 12:21     ` Alexander Turenko
2020-04-10 16:36 ` [Tarantool-patches] [PATCH 00/13] Popen Lua API: preliminary patches Kirill Yukhin

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=a1b0d4e4dc4ecad001e0cb0e778e36342303fde3.1586486220.git.alexander.turenko@tarantool.org \
    --to=alexander.turenko@tarantool.org \
    --cc=gorcunov@gmail.com \
    --cc=tarantool-patches@dev.tarantool.org \
    --subject='Re: [Tarantool-patches] [PATCH 06/13] popen: decouple logger fd from stderr' \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox