[gentoo-commits] proj/portage:master commit in: lib/_emerge/, man/, lib/portage/package/ebuild/_config/, ...

[Zac Medico]

commit:     73f72f526a66b9953a46868cc1390fde2820997f
Author:     Zac Medico <zmedico <AT> gentoo <DOT> org>
AuthorDate: Sun Mar  1 02:17:52 2020 +0000
Commit:     Zac Medico <zmedico <AT> gentoo <DOT> org>
CommitDate: Sun Mar  1 04:29:41 2020 +0000
URL:        https://gitweb.gentoo.org/proj/portage.git/commit/?id=73f72f52

Support PORTAGE_LOG_FILTER_FILE (bug 709746)

This variable specifies a command that filters build log output to a
log file. The plan is to extend this to support a separate filter for
tty output in the future.

In order to enable the EbuildPhase class to write elog messages to
the build log with PORTAGE_LOG_FILTER_FILE support, convert its _elog
method to a coroutine, and add a SchedulerInterface async_output
method for it to use.

Bug: https://bugs.gentoo.org/709746
Signed-off-by: Zac Medico <zmedico <AT> gentoo.org>

 lib/_emerge/AbstractEbuildProcess.py               |   2 +
 lib/_emerge/EbuildPhase.py                         |  36 +++++--
 lib/_emerge/SpawnProcess.py                        |  32 ++++--
 .../package/ebuild/_config/special_env_vars.py     |   8 +-
 lib/portage/util/_async/BuildLogger.py             | 116 +++++++++++++++++++++
 lib/portage/util/_async/SchedulerInterface.py      |  32 +++++-
 man/make.conf.5                                    |   7 +-
 7 files changed, 213 insertions(+), 20 deletions(-)

diff --git a/lib/_emerge/AbstractEbuildProcess.py b/lib/_emerge/AbstractEbuildProcess.py
index d1a6d1c4e..3732f80ed 100644
--- a/lib/_emerge/AbstractEbuildProcess.py
+++ b/lib/_emerge/AbstractEbuildProcess.py
@@ -181,6 +181,8 @@ class AbstractEbuildProcess(SpawnProcess):
 			null_fd = os.open('/dev/null', os.O_RDONLY)
 			self.fd_pipes[0] = null_fd
 
+		self.log_filter_file = self.settings.get('PORTAGE_LOG_FILTER_FILE')
+
 		try:
 			yield SpawnProcess._async_start(self)
 		finally:

diff --git a/lib/_emerge/EbuildPhase.py b/lib/_emerge/EbuildPhase.py
index f6b380e05..927a74b98 100644
--- a/lib/_emerge/EbuildPhase.py
+++ b/lib/_emerge/EbuildPhase.py
@@ -26,6 +26,8 @@ from portage.package.ebuild.prepare_build_dirs import (_prepare_workdir,
 from portage.util.futures.compat_coroutine import coroutine, coroutine_return
 from portage.util import writemsg
 from portage.util._async.AsyncTaskFuture import AsyncTaskFuture
+from portage.util._async.BuildLogger import BuildLogger
+from portage.util.futures import asyncio
 from portage.util.futures.executor.fork import ForkExecutor
 
 try:
@@ -130,7 +132,7 @@ class EbuildPhase(CompositeTask):
 			# Force background=True for this header since it's intended
 			# for the log and it doesn't necessarily need to be visible
 			# elsewhere.
-			self._elog('einfo', msg, background=True)
+			yield self._elog('einfo', msg, background=True)
 
 		if self.phase == 'package':
 			if 'PORTAGE_BINPKG_TMPFILE' not in self.settings:
@@ -392,6 +394,7 @@ class EbuildPhase(CompositeTask):
 		self.returncode = 1
 		self.wait()
 
+	@coroutine
 	def _elog(self, elog_funcname, lines, background=None):
 		if background is None:
 			background = self.background
@@ -408,11 +411,30 @@ class EbuildPhase(CompositeTask):
 			portage.output.havecolor = global_havecolor
 		msg = out.getvalue()
 		if msg:
-			log_path = None
-			if self.settings.get("PORTAGE_BACKGROUND") != "subprocess":
-				log_path = self.settings.get("PORTAGE_LOG_FILE")
-			self.scheduler.output(msg, log_path=log_path,
-				background=background)
+			build_logger = None
+			try:
+				log_file = None
+				log_path = None
+				if self.settings.get("PORTAGE_BACKGROUND") != "subprocess":
+					log_path = self.settings.get("PORTAGE_LOG_FILE")
+				if log_path:
+					build_logger = BuildLogger(env=self.settings.environ(),
+						log_path=log_path,
+						log_filter_file=self.settings.get('PORTAGE_LOG_FILTER_FILE'),
+						scheduler=self.scheduler)
+					yield build_logger.async_start()
+					log_file = build_logger.stdin
+
+				yield self.scheduler.async_output(msg, log_file=log_file,
+					background=background)
+
+				if build_logger is not None:
+					build_logger.stdin.close()
+					yield build_logger.async_wait()
+			except asyncio.CancelledError:
+				if build_logger is not None:
+					build_logger.cancel()
+				raise
 
 
 class _PostPhaseCommands(CompositeTask):
@@ -481,4 +503,4 @@ class _PostPhaseCommands(CompositeTask):
 			qa_msg.extend("\t%s: %s" % (filename, " ".join(sorted(soname_deps)))
 				for filename, soname_deps in unresolved)
 			qa_msg.append("")
-			self.elog("eqawarn", qa_msg)
+			yield self.elog("eqawarn", qa_msg)

diff --git a/lib/_emerge/SpawnProcess.py b/lib/_emerge/SpawnProcess.py
index ab7971ca8..34668b287 100644
--- a/lib/_emerge/SpawnProcess.py
+++ b/lib/_emerge/SpawnProcess.py
@@ -19,6 +19,7 @@ from portage.const import BASH_BINARY
 from portage.localization import _
 from portage.output import EOutput
 from portage.util import writemsg_level
+from portage.util._async.BuildLogger import BuildLogger
 from portage.util._async.PipeLogger import PipeLogger
 from portage.util.futures import asyncio
 from portage.util.futures.compat_coroutine import coroutine
@@ -36,7 +37,7 @@ class SpawnProcess(SubProcess):
 		"path_lookup", "pre_exec", "close_fds", "cgroup",
 		"unshare_ipc", "unshare_mount", "unshare_pid", "unshare_net")
 
-	__slots__ = ("args",) + \
+	__slots__ = ("args", "log_filter_file") + \
 		_spawn_kwarg_names + ("_main_task", "_selinux_type",)
 
 	# Max number of attempts to kill the processes listed in cgroup.procs,
@@ -142,30 +143,45 @@ class SpawnProcess(SubProcess):
 						fcntl.fcntl(stdout_fd,
 						fcntl.F_GETFD) | fcntl.FD_CLOEXEC)
 
-		pipe_logger = PipeLogger(background=self.background,
-			scheduler=self.scheduler, input_fd=master_fd,
-			log_file_path=log_file_path,
-			stdout_fd=stdout_fd)
+		build_logger = BuildLogger(env=self.env,
+			log_path=log_file_path,
+			log_filter_file=self.log_filter_file,
+			scheduler=self.scheduler)
+
 		self._registered = True
+		pipe_logger = None
 		try:
+			yield build_logger.async_start()
+
+			pipe_logger = PipeLogger(background=self.background,
+				scheduler=self.scheduler, input_fd=master_fd,
+				log_file_path=build_logger.stdin,
+				stdout_fd=stdout_fd)
+
 			yield pipe_logger.async_start()
 		except asyncio.CancelledError:
-			if pipe_logger.poll() is None:
+			if pipe_logger is not None and pipe_logger.poll() is None:
 				pipe_logger.cancel()
+			if build_logger.poll() is None:
+				build_logger.cancel()
 			raise
 
 		self._main_task = asyncio.ensure_future(
-			self._main(pipe_logger), loop=self.scheduler)
+			self._main(pipe_logger, build_logger), loop=self.scheduler)
 		self._main_task.add_done_callback(self._main_exit)
 
 	@coroutine
-	def _main(self, pipe_logger):
+	def _main(self, pipe_logger, build_logger):
 		try:
 			if pipe_logger.poll() is None:
 				yield pipe_logger.async_wait()
+			if build_logger.poll() is None:
+				yield build_logger.async_wait()
 		except asyncio.CancelledError:
 			if pipe_logger.poll() is None:
 				pipe_logger.cancel()
+			if build_logger.poll() is None:
+				build_logger.cancel()
 			raise
 
 	def _main_exit(self, main_task):

diff --git a/lib/portage/package/ebuild/_config/special_env_vars.py b/lib/portage/package/ebuild/_config/special_env_vars.py
index dc01339f7..dd8105123 100644
--- a/lib/portage/package/ebuild/_config/special_env_vars.py
+++ b/lib/portage/package/ebuild/_config/special_env_vars.py
@@ -1,4 +1,4 @@
-# Copyright 2010-2019 Gentoo Authors
+# Copyright 2010-2020 Gentoo Authors
 # Distributed under the terms of the GNU General Public License v2
 
 from __future__ import unicode_literals
@@ -175,7 +175,7 @@ environ_filter += [
 	"PORTAGE_RO_DISTDIRS",
 	"PORTAGE_RSYNC_EXTRA_OPTS", "PORTAGE_RSYNC_OPTS",
 	"PORTAGE_RSYNC_RETRIES", "PORTAGE_SSH_OPTS", "PORTAGE_SYNC_STALE",
-	"PORTAGE_USE",
+	"PORTAGE_USE", "PORTAGE_LOG_FILTER_FILE",
 	"PORTAGE_LOGDIR", "PORTAGE_LOGDIR_CLEAN",
 	"QUICKPKG_DEFAULT_OPTS", "REPOMAN_DEFAULT_OPTS",
 	"RESUMECOMMAND", "RESUMECOMMAND_FTP",
@@ -204,7 +204,9 @@ default_globals = {
 	'PORTAGE_BZIP2_COMMAND':    'bzip2',
 }
 
-validate_commands = ('PORTAGE_BZIP2_COMMAND', 'PORTAGE_BUNZIP2_COMMAND',)
+validate_commands = ('PORTAGE_BZIP2_COMMAND', 'PORTAGE_BUNZIP2_COMMAND',
+	'PORTAGE_LOG_FILTER_FILE',
+)
 
 # To enhance usability, make some vars case insensitive
 # by forcing them to lower case.

diff --git a/lib/portage/util/_async/BuildLogger.py b/lib/portage/util/_async/BuildLogger.py
new file mode 100644
index 000000000..4873d9750
--- /dev/null
+++ b/lib/portage/util/_async/BuildLogger.py
@@ -0,0 +1,116 @@
+# Copyright 2020 Gentoo Authors
+# Distributed under the terms of the GNU General Public License v2
+
+from portage import os
+from portage.util import shlex_split
+from _emerge.AsynchronousTask import AsynchronousTask
+from portage.util._async.PipeLogger import PipeLogger
+from portage.util.futures import asyncio
+from portage.util.futures.compat_coroutine import coroutine
+
+
+class BuildLogger(AsynchronousTask):
+	"""
+	Write to a log file, with compression support provided by PipeLogger.
+	If the log_filter_file parameter is specified, then it is interpreted
+	as a command to execute which filters log output (see the
+	PORTAGE_LOG_FILTER_FILE variable in make.conf(5)). The stdin property
+	provides access to a writable binary file stream (refers to a pipe)
+	that log content should be written to (usually redirected from
+	subprocess stdout and stderr streams).
+	"""
+
+	__slots__ = ('env', 'log_path', 'log_filter_file', '_main_task', '_stdin')
+
+	@property
+	def stdin(self):
+		return self._stdin
+
+	def _start(self):
+		self.scheduler.run_until_complete(self._async_start())
+
+	@coroutine
+	def _async_start(self):
+		pipe_logger = None
+		filter_proc = None
+		try:
+			log_input = None
+			if self.log_path is not None:
+				log_filter_file = self.log_filter_file
+				if log_filter_file is not None:
+					split_value = shlex_split(log_filter_file)
+					log_filter_file = split_value if split_value else None
+				if log_filter_file:
+					filter_input, stdin = os.pipe()
+					log_input, filter_output = os.pipe()
+					try:
+						filter_proc = yield asyncio.create_subprocess_exec(
+							*log_filter_file,
+							env=self.env,
+							stdin=filter_input,
+							stdout=filter_output,
+							stderr=filter_output,
+							loop=self.scheduler)
+					except EnvironmentError:
+						# Maybe the command is missing or broken somehow...
+						os.close(filter_input)
+						os.close(stdin)
+						os.close(log_input)
+						os.close(filter_output)
+					else:
+						self._stdin = os.fdopen(stdin, 'wb', 0)
+						os.close(filter_input)
+						os.close(filter_output)
+
+			if self._stdin is None:
+				# Since log_filter_file is unspecified or refers to a file
+				# that is missing or broken somehow, create a pipe that
+				# logs directly to pipe_logger.
+				log_input, stdin = os.pipe()
+				self._stdin = os.fdopen(stdin, 'wb', 0)
+
+			# Set background=True so that pipe_logger does not log to stdout.
+			pipe_logger = PipeLogger(background=True,
+				scheduler=self.scheduler, input_fd=log_input,
+				log_file_path=self.log_path)
+
+			yield pipe_logger.async_start()
+		except asyncio.CancelledError:
+			if pipe_logger is not None and pipe_logger.poll() is None:
+				pipe_logger.cancel()
+			if filter_proc is not None and filter_proc.returncode is None:
+				filter_proc.terminate()
+			raise
+
+		self._main_task = asyncio.ensure_future(
+			self._main(pipe_logger, filter_proc=filter_proc), loop=self.scheduler)
+		self._main_task.add_done_callback(self._main_exit)
+
+	def _cancel(self):
+		if self._main_task is not None:
+			self._main_task.done() or self._main_task.cancel()
+		if self._stdin is not None and not self._stdin.closed:
+			self._stdin.close()
+
+	@coroutine
+	def _main(self, pipe_logger, filter_proc=None):
+		try:
+			if pipe_logger.poll() is None:
+				yield pipe_logger.async_wait()
+			if filter_proc is not None and filter_proc.returncode is None:
+				yield filter_proc.wait()
+		except asyncio.CancelledError:
+			if pipe_logger.poll() is None:
+				pipe_logger.cancel()
+			if filter_proc is not None and filter_proc.returncode is None:
+				filter_proc.terminate()
+			raise
+
+	def _main_exit(self, main_task):
+		try:
+			main_task.result()
+		except asyncio.CancelledError:
+			self.cancel()
+			self._was_cancelled()
+		self.returncode = self.returncode or 0
+		self._async_wait()

diff --git a/lib/portage/util/_async/SchedulerInterface.py b/lib/portage/util/_async/SchedulerInterface.py
index ec6417da1..3ff250d1d 100644
--- a/lib/portage/util/_async/SchedulerInterface.py
+++ b/lib/portage/util/_async/SchedulerInterface.py
@@ -1,4 +1,4 @@
-# Copyright 2012-2018 Gentoo Foundation
+# Copyright 2012-2020 Gentoo Authors
 # Distributed under the terms of the GNU General Public License v2
 
 import gzip
@@ -7,6 +7,8 @@ import errno
 from portage import _encodings
 from portage import _unicode_encode
 from portage.util import writemsg_level
+from portage.util.futures._asyncio.streams import _writer
+from portage.util.futures.compat_coroutine import coroutine
 from ..SlotObject import SlotObject
 
 class SchedulerInterface(SlotObject):
@@ -53,6 +55,34 @@ class SchedulerInterface(SlotObject):
 	def _return_false():
 		return False
 
+	@coroutine
+	def async_output(self, msg, log_file=None, background=None,
+		level=0, noiselevel=-1):
+		"""
+		Output a msg to stdio (if not in background) and to a log file
+		if provided.
+
+		@param msg: a message string, including newline if appropriate
+		@type msg: str
+		@param log_file: log file in binary mode
+		@type log_file: file
+		@param background: send messages only to log (not to stdio)
+		@type background: bool
+		@param level: a numeric logging level (see the logging module)
+		@type level: int
+		@param noiselevel: passed directly to writemsg
+		@type noiselevel: int
+		"""
+		global_background = self._is_background()
+		if background is None or global_background:
+			background = global_background
+
+		if not background:
+			writemsg_level(msg, level=level, noiselevel=noiselevel)
+
+		if log_file is not None:
+			yield _writer(log_file, _unicode_encode(msg))
+
 	def output(self, msg, log_path=None, background=None,
 		level=0, noiselevel=-1):
 		"""

diff --git a/man/make.conf.5 b/man/make.conf.5
index f82fed65a..baecd283a 100644
--- a/man/make.conf.5
+++ b/man/make.conf.5
@@ -1,4 +1,4 @@
-.TH "MAKE.CONF" "5" "Nov 2019" "Portage VERSION" "Portage"
+.TH "MAKE.CONF" "5" "Mar 2020" "Portage VERSION" "Portage"
 .SH "NAME"
 make.conf \- custom settings for Portage
 .SH "SYNOPSIS"
@@ -979,6 +979,11 @@ with an integer pid. For example, a value of "ionice \-c 3 \-p \\${PID}"
 will set idle io priority. For more information about ionice, see
 \fBionice\fR(1). This variable is unset by default.
 .TP
+.B PORTAGE_LOG_FILTER_FILE
+This variable specifies a command that filters build log output to a
+log file. In order to filter ANSI escape codes from build logs,
+\fBansifilter\fR(1) is a convenient setting for this variable.
+.TP
 .B PORTAGE_LOGDIR
 This variable defines the directory in which per\-ebuild logs are kept.
 Logs are created only when this is set. They are stored as