1 |
This variable specifies a command that filters build log output to a |
2 |
log file. The plan is to extend this to support a separate filter for |
3 |
tty output in the future. |
4 |
|
5 |
In order to enable the EbuildPhase class to write elog messages to |
6 |
the build log with PORTAGE_LOG_FILTER_FILE_CMD support, convert its |
7 |
_elog method to a coroutine, and add a SchedulerInterface async_output |
8 |
method for it to use. |
9 |
|
10 |
Use a new BuildLogger class to manage log output (with or without a |
11 |
filter command), with compression support provided by PipeLogger. |
12 |
BuildLogger has a stdin property which provides access to a writable |
13 |
binary file stream (refers to a pipe) that log content is written to. |
14 |
|
15 |
Bug: https://bugs.gentoo.org/709746 |
16 |
Signed-off-by: Zac Medico <zmedico@g.o> |
17 |
--- |
18 |
lib/_emerge/AbstractEbuildProcess.py | 2 + |
19 |
lib/_emerge/EbuildPhase.py | 47 ++++++-- |
20 |
lib/_emerge/SpawnProcess.py | 56 ++++++--- |
21 |
.../ebuild/_config/special_env_vars.py | 8 +- |
22 |
lib/portage/util/_async/BuildLogger.py | 109 ++++++++++++++++++ |
23 |
lib/portage/util/_async/SchedulerInterface.py | 32 ++++- |
24 |
man/make.conf.5 | 7 +- |
25 |
7 files changed, 236 insertions(+), 25 deletions(-) |
26 |
create mode 100644 lib/portage/util/_async/BuildLogger.py |
27 |
|
28 |
diff --git a/lib/_emerge/AbstractEbuildProcess.py b/lib/_emerge/AbstractEbuildProcess.py |
29 |
index 1c1955cfe..5fd4e3a1e 100644 |
30 |
--- a/lib/_emerge/AbstractEbuildProcess.py |
31 |
+++ b/lib/_emerge/AbstractEbuildProcess.py |
32 |
@@ -196,6 +196,8 @@ class AbstractEbuildProcess(SpawnProcess): |
33 |
null_fd = os.open('/dev/null', os.O_RDONLY) |
34 |
self.fd_pipes[0] = null_fd |
35 |
|
36 |
+ self.log_filter_file = self.settings.get('PORTAGE_LOG_FILTER_FILE_CMD') |
37 |
+ |
38 |
try: |
39 |
SpawnProcess._start(self) |
40 |
finally: |
41 |
diff --git a/lib/_emerge/EbuildPhase.py b/lib/_emerge/EbuildPhase.py |
42 |
index 477e0ba97..ddb3dc719 100644 |
43 |
--- a/lib/_emerge/EbuildPhase.py |
44 |
+++ b/lib/_emerge/EbuildPhase.py |
45 |
@@ -26,6 +26,8 @@ from portage.package.ebuild.prepare_build_dirs import (_prepare_workdir, |
46 |
from portage.util.futures.compat_coroutine import coroutine |
47 |
from portage.util import writemsg |
48 |
from portage.util._async.AsyncTaskFuture import AsyncTaskFuture |
49 |
+from portage.util._async.BuildLogger import BuildLogger |
50 |
+from portage.util.futures import asyncio |
51 |
from portage.util.futures.executor.fork import ForkExecutor |
52 |
|
53 |
try: |
54 |
@@ -69,6 +71,11 @@ class EbuildPhase(CompositeTask): |
55 |
_locked_phases = ("setup", "preinst", "postinst", "prerm", "postrm") |
56 |
|
57 |
def _start(self): |
58 |
+ future = asyncio.ensure_future(self._async_start(), loop=self.scheduler) |
59 |
+ self._start_task(AsyncTaskFuture(future=future), self._async_start_exit) |
60 |
+ |
61 |
+ @coroutine |
62 |
+ def _async_start(self): |
63 |
|
64 |
need_builddir = self.phase not in EbuildProcess._phases_without_builddir |
65 |
|
66 |
@@ -126,7 +133,7 @@ class EbuildPhase(CompositeTask): |
67 |
# Force background=True for this header since it's intended |
68 |
# for the log and it doesn't necessarily need to be visible |
69 |
# elsewhere. |
70 |
- self._elog('einfo', msg, background=True) |
71 |
+ yield self._elog('einfo', msg, background=True) |
72 |
|
73 |
if self.phase == 'package': |
74 |
if 'PORTAGE_BINPKG_TMPFILE' not in self.settings: |
75 |
@@ -134,6 +141,12 @@ class EbuildPhase(CompositeTask): |
76 |
os.path.join(self.settings['PKGDIR'], |
77 |
self.settings['CATEGORY'], self.settings['PF']) + '.tbz2' |
78 |
|
79 |
+ def _async_start_exit(self, task): |
80 |
+ task.future.cancelled() or task.future.result() |
81 |
+ if self._default_exit(task) != os.EX_OK: |
82 |
+ self.wait() |
83 |
+ return |
84 |
+ |
85 |
if self.phase in ("pretend", "prerm"): |
86 |
env_extractor = BinpkgEnvExtractor(background=self.background, |
87 |
scheduler=self.scheduler, settings=self.settings) |
88 |
@@ -391,6 +404,7 @@ class EbuildPhase(CompositeTask): |
89 |
self.returncode = 1 |
90 |
self.wait() |
91 |
|
92 |
+ @coroutine |
93 |
def _elog(self, elog_funcname, lines, background=None): |
94 |
if background is None: |
95 |
background = self.background |
96 |
@@ -407,11 +421,30 @@ class EbuildPhase(CompositeTask): |
97 |
portage.output.havecolor = global_havecolor |
98 |
msg = out.getvalue() |
99 |
if msg: |
100 |
- log_path = None |
101 |
- if self.settings.get("PORTAGE_BACKGROUND") != "subprocess": |
102 |
- log_path = self.settings.get("PORTAGE_LOG_FILE") |
103 |
- self.scheduler.output(msg, log_path=log_path, |
104 |
- background=background) |
105 |
+ build_logger = None |
106 |
+ try: |
107 |
+ log_file = None |
108 |
+ log_path = None |
109 |
+ if self.settings.get("PORTAGE_BACKGROUND") != "subprocess": |
110 |
+ log_path = self.settings.get("PORTAGE_LOG_FILE") |
111 |
+ if log_path: |
112 |
+ build_logger = BuildLogger(env=self.settings.environ(), |
113 |
+ log_path=log_path, |
114 |
+ log_filter_file=self.settings.get('PORTAGE_LOG_FILTER_FILE_CMD'), |
115 |
+ scheduler=self.scheduler) |
116 |
+ build_logger.start() |
117 |
+ log_file = build_logger.stdin |
118 |
+ |
119 |
+ yield self.scheduler.async_output(msg, log_file=log_file, |
120 |
+ background=background) |
121 |
+ |
122 |
+ if build_logger is not None: |
123 |
+ build_logger.stdin.close() |
124 |
+ yield build_logger.async_wait() |
125 |
+ except asyncio.CancelledError: |
126 |
+ if build_logger is not None: |
127 |
+ build_logger.cancel() |
128 |
+ raise |
129 |
|
130 |
|
131 |
class _PostPhaseCommands(CompositeTask): |
132 |
@@ -480,4 +513,4 @@ class _PostPhaseCommands(CompositeTask): |
133 |
qa_msg.extend("\t%s: %s" % (filename, " ".join(sorted(soname_deps))) |
134 |
for filename, soname_deps in unresolved) |
135 |
qa_msg.append("") |
136 |
- self.elog("eqawarn", qa_msg) |
137 |
+ yield self.elog("eqawarn", qa_msg) |
138 |
diff --git a/lib/_emerge/SpawnProcess.py b/lib/_emerge/SpawnProcess.py |
139 |
index 395d66bb9..160ff023b 100644 |
140 |
--- a/lib/_emerge/SpawnProcess.py |
141 |
+++ b/lib/_emerge/SpawnProcess.py |
142 |
@@ -19,7 +19,10 @@ from portage.const import BASH_BINARY |
143 |
from portage.localization import _ |
144 |
from portage.output import EOutput |
145 |
from portage.util import writemsg_level |
146 |
+from portage.util._async.BuildLogger import BuildLogger |
147 |
from portage.util._async.PipeLogger import PipeLogger |
148 |
+from portage.util.futures import asyncio |
149 |
+from portage.util.futures.compat_coroutine import coroutine |
150 |
|
151 |
class SpawnProcess(SubProcess): |
152 |
|
153 |
@@ -34,8 +37,8 @@ class SpawnProcess(SubProcess): |
154 |
"path_lookup", "pre_exec", "close_fds", "cgroup", |
155 |
"unshare_ipc", "unshare_mount", "unshare_pid", "unshare_net") |
156 |
|
157 |
- __slots__ = ("args",) + \ |
158 |
- _spawn_kwarg_names + ("_pipe_logger", "_selinux_type",) |
159 |
+ __slots__ = ("args", "log_filter_file") + \ |
160 |
+ _spawn_kwarg_names + ("_main_task", "_selinux_type",) |
161 |
|
162 |
# Max number of attempts to kill the processes listed in cgroup.procs, |
163 |
# given that processes may fork before they can be killed. |
164 |
@@ -137,13 +140,43 @@ class SpawnProcess(SubProcess): |
165 |
fcntl.fcntl(stdout_fd, |
166 |
fcntl.F_GETFD) | fcntl.FD_CLOEXEC) |
167 |
|
168 |
- self._pipe_logger = PipeLogger(background=self.background, |
169 |
+ build_logger = BuildLogger(env=self.env, |
170 |
+ log_path=log_file_path, |
171 |
+ log_filter_file=self.log_filter_file, |
172 |
+ scheduler=self.scheduler) |
173 |
+ build_logger.start() |
174 |
+ |
175 |
+ pipe_logger = PipeLogger(background=self.background, |
176 |
scheduler=self.scheduler, input_fd=master_fd, |
177 |
- log_file_path=log_file_path, |
178 |
+ log_file_path=build_logger.stdin, |
179 |
stdout_fd=stdout_fd) |
180 |
- self._pipe_logger.addExitListener(self._pipe_logger_exit) |
181 |
- self._pipe_logger.start() |
182 |
+ |
183 |
+ pipe_logger.start() |
184 |
+ |
185 |
self._registered = True |
186 |
+ self._main_task = asyncio.ensure_future(self._main(build_logger, pipe_logger), loop=self.scheduler) |
187 |
+ self._main_task.add_done_callback(self._main_exit) |
188 |
+ |
189 |
+ @coroutine |
190 |
+ def _main(self, build_logger, pipe_logger): |
191 |
+ try: |
192 |
+ if pipe_logger.poll() is None: |
193 |
+ yield pipe_logger.async_wait() |
194 |
+ if build_logger.poll() is None: |
195 |
+ yield build_logger.async_wait() |
196 |
+ except asyncio.CancelledError: |
197 |
+ if pipe_logger.poll() is None: |
198 |
+ pipe_logger.cancel() |
199 |
+ if build_logger.poll() is None: |
200 |
+ build_logger.cancel() |
201 |
+ raise |
202 |
+ |
203 |
+ def _main_exit(self, main_task): |
204 |
+ try: |
205 |
+ main_task.result() |
206 |
+ except asyncio.CancelledError: |
207 |
+ self.cancel() |
208 |
+ self._async_waitpid() |
209 |
|
210 |
def _can_log(self, slave_fd): |
211 |
return True |
212 |
@@ -167,20 +200,17 @@ class SpawnProcess(SubProcess): |
213 |
|
214 |
return spawn_func(args, **kwargs) |
215 |
|
216 |
- def _pipe_logger_exit(self, pipe_logger): |
217 |
- self._pipe_logger = None |
218 |
- self._async_waitpid() |
219 |
- |
220 |
def _unregister(self): |
221 |
SubProcess._unregister(self) |
222 |
if self.cgroup is not None: |
223 |
self._cgroup_cleanup() |
224 |
self.cgroup = None |
225 |
- if self._pipe_logger is not None: |
226 |
- self._pipe_logger.cancel() |
227 |
- self._pipe_logger = None |
228 |
+ if self._main_task is not None: |
229 |
+ self._main_task.done() or self._main_task.cancel() |
230 |
|
231 |
def _cancel(self): |
232 |
+ if self._main_task is not None: |
233 |
+ self._main_task.done() or self._main_task.cancel() |
234 |
SubProcess._cancel(self) |
235 |
self._cgroup_cleanup() |
236 |
|
237 |
diff --git a/lib/portage/package/ebuild/_config/special_env_vars.py b/lib/portage/package/ebuild/_config/special_env_vars.py |
238 |
index 440dd00b2..f44cb9b1b 100644 |
239 |
--- a/lib/portage/package/ebuild/_config/special_env_vars.py |
240 |
+++ b/lib/portage/package/ebuild/_config/special_env_vars.py |
241 |
@@ -1,4 +1,4 @@ |
242 |
-# Copyright 2010-2019 Gentoo Authors |
243 |
+# Copyright 2010-2020 Gentoo Authors |
244 |
# Distributed under the terms of the GNU General Public License v2 |
245 |
|
246 |
from __future__ import unicode_literals |
247 |
@@ -175,7 +175,7 @@ environ_filter += [ |
248 |
"PORTAGE_RO_DISTDIRS", |
249 |
"PORTAGE_RSYNC_EXTRA_OPTS", "PORTAGE_RSYNC_OPTS", |
250 |
"PORTAGE_RSYNC_RETRIES", "PORTAGE_SSH_OPTS", "PORTAGE_SYNC_STALE", |
251 |
- "PORTAGE_USE", |
252 |
+ "PORTAGE_USE", "PORTAGE_LOG_FILTER_FILE_CMD", |
253 |
"PORTAGE_LOGDIR", "PORTAGE_LOGDIR_CLEAN", |
254 |
"QUICKPKG_DEFAULT_OPTS", "REPOMAN_DEFAULT_OPTS", |
255 |
"RESUMECOMMAND", "RESUMECOMMAND_FTP", |
256 |
@@ -204,7 +204,9 @@ default_globals = { |
257 |
'PORTAGE_BZIP2_COMMAND': 'bzip2', |
258 |
} |
259 |
|
260 |
-validate_commands = ('PORTAGE_BZIP2_COMMAND', 'PORTAGE_BUNZIP2_COMMAND',) |
261 |
+validate_commands = ('PORTAGE_BZIP2_COMMAND', 'PORTAGE_BUNZIP2_COMMAND', |
262 |
+ 'PORTAGE_LOG_FILTER_FILE_CMD', |
263 |
+) |
264 |
|
265 |
# To enhance usability, make some vars case insensitive |
266 |
# by forcing them to lower case. |
267 |
diff --git a/lib/portage/util/_async/BuildLogger.py b/lib/portage/util/_async/BuildLogger.py |
268 |
new file mode 100644 |
269 |
index 000000000..f5fea77ea |
270 |
--- /dev/null |
271 |
+++ b/lib/portage/util/_async/BuildLogger.py |
272 |
@@ -0,0 +1,109 @@ |
273 |
+# Copyright 2020 Gentoo Authors |
274 |
+# Distributed under the terms of the GNU General Public License v2 |
275 |
+ |
276 |
+import subprocess |
277 |
+ |
278 |
+from portage import os |
279 |
+from portage.util import shlex_split |
280 |
+from _emerge.AsynchronousTask import AsynchronousTask |
281 |
+from portage.util._async.PipeLogger import PipeLogger |
282 |
+from portage.util._async.PopenProcess import PopenProcess |
283 |
+from portage.util.futures import asyncio |
284 |
+from portage.util.futures.compat_coroutine import coroutine |
285 |
+ |
286 |
+ |
287 |
+class BuildLogger(AsynchronousTask): |
288 |
+ """ |
289 |
+ Write to a log file, with compression support provided by PipeLogger. |
290 |
+ If the log_filter_file parameter is specified, then it is interpreted |
291 |
+ as a command to execute which filters log output (see the |
292 |
+ PORTAGE_LOG_FILTER_FILE_CMD variable in make.conf(5)). The stdin property |
293 |
+ provides access to a writable binary file stream (refers to a pipe) |
294 |
+ that log content should be written to (usually redirected from |
295 |
+ subprocess stdout and stderr streams). |
296 |
+ """ |
297 |
+ |
298 |
+ __slots__ = ('env', 'log_path', 'log_filter_file', '_main_task', '_stdin') |
299 |
+ |
300 |
+ @property |
301 |
+ def stdin(self): |
302 |
+ return self._stdin |
303 |
+ |
304 |
+ def _start(self): |
305 |
+ filter_proc = None |
306 |
+ log_input = None |
307 |
+ if self.log_path is not None: |
308 |
+ log_filter_file = self.log_filter_file |
309 |
+ if log_filter_file is not None: |
310 |
+ split_value = shlex_split(log_filter_file) |
311 |
+ log_filter_file = split_value if split_value else None |
312 |
+ if log_filter_file: |
313 |
+ filter_input, stdin = os.pipe() |
314 |
+ log_input, filter_output = os.pipe() |
315 |
+ try: |
316 |
+ filter_proc = PopenProcess( |
317 |
+ proc=subprocess.Popen( |
318 |
+ log_filter_file, |
319 |
+ env=self.env, |
320 |
+ stdin=filter_input, |
321 |
+ stdout=filter_output, |
322 |
+ stderr=filter_output, |
323 |
+ ), |
324 |
+ scheduler=self.scheduler, |
325 |
+ ) |
326 |
+ filter_proc.start() |
327 |
+ except EnvironmentError: |
328 |
+ # Maybe the command is missing or broken somehow... |
329 |
+ os.close(filter_input) |
330 |
+ os.close(stdin) |
331 |
+ os.close(log_input) |
332 |
+ os.close(filter_output) |
333 |
+ else: |
334 |
+ self._stdin = os.fdopen(stdin, 'wb', 0) |
335 |
+ os.close(filter_input) |
336 |
+ os.close(filter_output) |
337 |
+ |
338 |
+ if self._stdin is None: |
339 |
+ # Since log_filter_file is unspecified or refers to a file |
340 |
+ # that is missing or broken somehow, create a pipe that |
341 |
+ # logs directly to pipe_logger. |
342 |
+ log_input, stdin = os.pipe() |
343 |
+ self._stdin = os.fdopen(stdin, 'wb', 0) |
344 |
+ |
345 |
+ # Set background=True so that pipe_logger does not log to stdout. |
346 |
+ pipe_logger = PipeLogger(background=True, |
347 |
+ scheduler=self.scheduler, input_fd=log_input, |
348 |
+ log_file_path=self.log_path) |
349 |
+ pipe_logger.start() |
350 |
+ |
351 |
+ self._main_task = asyncio.ensure_future(self._main(filter_proc, pipe_logger), loop=self.scheduler) |
352 |
+ self._main_task.add_done_callback(self._main_exit) |
353 |
+ |
354 |
+ @coroutine |
355 |
+ def _main(self, filter_proc, pipe_logger): |
356 |
+ try: |
357 |
+ if pipe_logger.poll() is None: |
358 |
+ yield pipe_logger.async_wait() |
359 |
+ if filter_proc is not None and filter_proc.poll() is None: |
360 |
+ yield filter_proc.async_wait() |
361 |
+ except asyncio.CancelledError: |
362 |
+ if pipe_logger.poll() is None: |
363 |
+ pipe_logger.cancel() |
364 |
+ if filter_proc is not None and filter_proc.poll() is None: |
365 |
+ filter_proc.cancel() |
366 |
+ raise |
367 |
+ |
368 |
+ def _cancel(self): |
369 |
+ if self._main_task is not None: |
370 |
+ self._main_task.done() or self._main_task.cancel() |
371 |
+ if self._stdin is not None and not self._stdin.closed: |
372 |
+ self._stdin.close() |
373 |
+ |
374 |
+ def _main_exit(self, main_task): |
375 |
+ try: |
376 |
+ main_task.result() |
377 |
+ except asyncio.CancelledError: |
378 |
+ self.cancel() |
379 |
+ self._was_cancelled() |
380 |
+ self.returncode = self.returncode or 0 |
381 |
+ self._async_wait() |
382 |
diff --git a/lib/portage/util/_async/SchedulerInterface.py b/lib/portage/util/_async/SchedulerInterface.py |
383 |
index ec6417da1..3ff250d1d 100644 |
384 |
--- a/lib/portage/util/_async/SchedulerInterface.py |
385 |
+++ b/lib/portage/util/_async/SchedulerInterface.py |
386 |
@@ -1,4 +1,4 @@ |
387 |
-# Copyright 2012-2018 Gentoo Foundation |
388 |
+# Copyright 2012-2020 Gentoo Authors |
389 |
# Distributed under the terms of the GNU General Public License v2 |
390 |
|
391 |
import gzip |
392 |
@@ -7,6 +7,8 @@ import errno |
393 |
from portage import _encodings |
394 |
from portage import _unicode_encode |
395 |
from portage.util import writemsg_level |
396 |
+from portage.util.futures._asyncio.streams import _writer |
397 |
+from portage.util.futures.compat_coroutine import coroutine |
398 |
from ..SlotObject import SlotObject |
399 |
|
400 |
class SchedulerInterface(SlotObject): |
401 |
@@ -53,6 +55,34 @@ class SchedulerInterface(SlotObject): |
402 |
def _return_false(): |
403 |
return False |
404 |
|
405 |
+ @coroutine |
406 |
+ def async_output(self, msg, log_file=None, background=None, |
407 |
+ level=0, noiselevel=-1): |
408 |
+ """ |
409 |
+ Output a msg to stdio (if not in background) and to a log file |
410 |
+ if provided. |
411 |
+ |
412 |
+ @param msg: a message string, including newline if appropriate |
413 |
+ @type msg: str |
414 |
+ @param log_file: log file in binary mode |
415 |
+ @type log_file: file |
416 |
+ @param background: send messages only to log (not to stdio) |
417 |
+ @type background: bool |
418 |
+ @param level: a numeric logging level (see the logging module) |
419 |
+ @type level: int |
420 |
+ @param noiselevel: passed directly to writemsg |
421 |
+ @type noiselevel: int |
422 |
+ """ |
423 |
+ global_background = self._is_background() |
424 |
+ if background is None or global_background: |
425 |
+ background = global_background |
426 |
+ |
427 |
+ if not background: |
428 |
+ writemsg_level(msg, level=level, noiselevel=noiselevel) |
429 |
+ |
430 |
+ if log_file is not None: |
431 |
+ yield _writer(log_file, _unicode_encode(msg)) |
432 |
+ |
433 |
def output(self, msg, log_path=None, background=None, |
434 |
level=0, noiselevel=-1): |
435 |
""" |
436 |
diff --git a/man/make.conf.5 b/man/make.conf.5 |
437 |
index a3bd662ae..eb812150f 100644 |
438 |
--- a/man/make.conf.5 |
439 |
+++ b/man/make.conf.5 |
440 |
@@ -1,4 +1,4 @@ |
441 |
-.TH "MAKE.CONF" "5" "May 2020" "Portage VERSION" "Portage" |
442 |
+.TH "MAKE.CONF" "5" "Jun 2020" "Portage VERSION" "Portage" |
443 |
.SH "NAME" |
444 |
make.conf \- custom settings for Portage |
445 |
.SH "SYNOPSIS" |
446 |
@@ -979,6 +979,11 @@ with an integer pid. For example, a value of "ionice \-c 3 \-p \\${PID}" |
447 |
will set idle io priority. For more information about ionice, see |
448 |
\fBionice\fR(1). This variable is unset by default. |
449 |
.TP |
450 |
+.B PORTAGE_LOG_FILTER_FILE_CMD |
451 |
+This variable specifies a command that filters build log output to a |
452 |
+log file. In order to filter ANSI escape codes from build logs, |
453 |
+\fBansifilter\fR(1) is a convenient setting for this variable. |
454 |
+.TP |
455 |
.B PORTAGE_LOGDIR |
456 |
This variable defines the directory in which per\-ebuild logs are kept. |
457 |
Logs are created only when this is set. They are stored as |
458 |
-- |
459 |
2.25.3 |