Skip to content

Commit

Permalink
Support PORTAGE_LOG_FILTER_FILE (bug 709746)
Browse files Browse the repository at this point in the history
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@gentoo.org>
  • Loading branch information
zmedico committed Mar 1, 2020
1 parent 69f1323 commit 73f72f5
Show file tree
Hide file tree
Showing 7 changed files with 213 additions and 20 deletions.
2 changes: 2 additions & 0 deletions lib/_emerge/AbstractEbuildProcess.py
Original file line number Diff line number Diff line change
Expand Up @@ -181,6 +181,8 @@ def _async_start(self):
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:
Expand Down
36 changes: 29 additions & 7 deletions lib/_emerge/EbuildPhase.py
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,8 @@
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:
Expand Down Expand Up @@ -130,7 +132,7 @@ def _async_start(self):
# 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:
Expand Down Expand Up @@ -392,6 +394,7 @@ def _fail_clean_exit(self, clean_phase):
self.returncode = 1
self.wait()

@coroutine
def _elog(self, elog_funcname, lines, background=None):
if background is None:
background = self.background
Expand All @@ -408,11 +411,30 @@ def _elog(self, elog_funcname, lines, background=None):
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):
Expand Down Expand Up @@ -481,4 +503,4 @@ def _soname_deps_qa(self):
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)
32 changes: 24 additions & 8 deletions lib/_emerge/SpawnProcess.py
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
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
Expand All @@ -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,
Expand Down Expand Up @@ -142,30 +143,45 @@ def _async_start(self):
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):
Expand Down
8 changes: 5 additions & 3 deletions lib/portage/package/ebuild/_config/special_env_vars.py
Original file line number Diff line number Diff line change
@@ -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
Expand Down Expand Up @@ -175,7 +175,7 @@
"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",
Expand Down Expand Up @@ -204,7 +204,9 @@
'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.
Expand Down
116 changes: 116 additions & 0 deletions lib/portage/util/_async/BuildLogger.py
Original file line number Diff line number Diff line change
@@ -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()
32 changes: 31 additions & 1 deletion lib/portage/util/_async/SchedulerInterface.py
Original file line number Diff line number Diff line change
@@ -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
Expand All @@ -7,6 +7,8 @@
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):
Expand Down Expand Up @@ -53,6 +55,34 @@ def __init__(self, event_loop, is_background=None, **kwargs):
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):
"""
Expand Down
7 changes: 6 additions & 1 deletion man/make.conf.5
Original file line number Diff line number Diff line change
@@ -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"
Expand Down Expand Up @@ -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
Expand Down

0 comments on commit 73f72f5

Please sign in to comment.