diff -ur portage-2.2.0_alpha52-orig/pym/portage/const.py portage-2.2.0_alpha52/pym/portage/const.py --- portage-2.2.0_alpha52-orig/pym/portage/const.py 2011-09-04 11:45:59 +0900 +++ portage-2.2.0_alpha52/pym/portage/const.py 2011-09-04 11:49:16 +0900 @@ -89,6 +89,7 @@ "allow-missing-manifests", "assume-digests", "binpkg-logs", "buildpkg", "buildsyspkg", "candy", "ccache", "chflags", "clean-logs", + "concise-progress", "collision-protect", "compress-build-logs", "digest", "distcc", "distcc-pump", "distlocks", "ebuild-locks", "fakeroot", "fail-clean", "fixpackages", "force-mirror", "getbinpkg", diff -ur portage-2.2.0_alpha52-orig/pym/portage/output.py portage-2.2.0_alpha52/pym/portage/output.py --- portage-2.2.0_alpha52-orig/pym/portage/output.py 2011-09-04 11:45:59 +0900 +++ portage-2.2.0_alpha52/pym/portage/output.py 2011-09-04 11:48:38 +0900 @@ -8,6 +8,7 @@ import formatter import re import sys +import time import portage portage.proxy.lazyimport.lazyimport(globals(), @@ -798,3 +799,101 @@ codes = _LazyInitColorMap(codes) _styles = _LazyInitColorMap(_styles) + +class EProgressBar: + """ + Implements a textual progress bar. + + @ivar progress: The current progress through the operation, in either + bytes or arbitrary units. + @type progress: IntType + @ivar total: The maximum value C{progress} is expected to reach, in the + same units as C{progress}. If zero or negative, assumed to be + unknown. + @type total: IntType + @ivar is_bytes: True if C{progress} and C{total} are byte counters, + otherwise false. Affects the manner in which the progress is + displayed. + @type is_bytes: Boolean + @ivar start_time: Time at which the operation was started (assumed to + be the time at which the progress bar was created). + @type start_time: Float + @ivar start_progress: The value of C{progress} when the operation was + started. + @type start_progress: IntType + @ivar term_columns: Width of terminal in characters. Defaults to the value + specified by the shell's C{COLUMNS} variable, else to the queried tty + size, else to C{80}. + @type term_columns: IntType + """ + + def __init__(self, total, progress = 0, is_bytes = False): + self.total = total + self.progress = progress + self.is_bytes = is_bytes + self.start_time = time.time() + self.start_progress = self.progress + lines, columns = get_term_size() + if columns <= 0: + columns = 80 + # Adjust columns so that eend works properly on a standard BSD console. + if os.environ.get("TERM") == "cons25": + columns = columns - 1 + self.term_columns = columns + + def __size_to_string(self, size): + if size >= 100000000000: + return "%uGB" % (size / 1000000000) + elif size >= 100000000: + return "%uMB" % (size / 1000000) + else: + return "%ukB" % (size / 1000) + + def update(self, progress = -1): + """ + Optionally updates the current progress value, then draws the + progress bar on the terminal. + + @param progress: I{(optional)} The current progress value. + @type progress: IntType + """ + if progress >= 0: + self.progress = progress + if self.is_bytes: + progress_string = self.__size_to_string(self.progress) + total_string = self.__size_to_string(self.total) + else: + progress_string = "" + total_string = "%d%% " % (self.progress*100 / self.total) + if self.total > 0: + bar_size = self.term_columns - 27 + time_string = "---:--" + elapsed_time = time.time() - self.start_time + elapsed_progress = self.progress - self.start_progress + progress_left = (self.total - self.start_progress) - elapsed_progress + if elapsed_time > 0 and elapsed_progress > 0: + import math + eta = int(math.ceil((elapsed_time * progress_left) / elapsed_progress)) + if eta > 1000*60-1: + eta = 1000*60-1 + time_string = "%3d:%02d" % (eta/60, eta%60) + if bar_size > 0: + bar_width = bar_size * self.progress / self.total + bar_string = "%-*s" % (bar_size, '=' * bar_width) + sys.stderr.write("%7s |%s| %7s %s\r" \ + % (progress_string, bar_string, total_string, time_string)) + else: + sys.stderr.write("%7s/%-7s ---:--\r" \ + % (progress_string, total_string, time_string)) + else: + sys.stderr.write("%7s\r" % progress_string) + sys.stdout.flush() + + def finish(self): + """ + Draws the progress bar on the terminal, then advances to the next + line so that subsequent terminal output does not overwrite the + progress bar. + """ + self.update() + writemsg("\n") diff -ur portage-2.2.0_alpha52-orig/pym/portage/package/ebuild/digestcheck.py portage-2.2.0_alpha52/pym/portage/package/ebuild/digestcheck.py --- portage-2.2.0_alpha52-orig/pym/portage/package/ebuild/digestcheck.py 2011-08-12 20:43:40 +0900 +++ portage-2.2.0_alpha52/pym/portage/package/ebuild/digestcheck.py 2011-09-04 11:48:38 +0900 @@ -55,7 +55,8 @@ else: return 1 eout = EOutput() - eout.quiet = mysettings.get("PORTAGE_QUIET", None) == "1" + eout.quiet = mysettings.get("PORTAGE_QUIET", None) == "1" \ + or "concise-progress" in mysettings.features try: if strict and "PORTAGE_PARALLEL_FETCHONLY" not in mysettings: eout.ebegin(_("checking ebuild checksums ;-)")) diff -ur portage-2.2.0_alpha52-orig/pym/portage/package/ebuild/doebuild.py portage-2.2.0_alpha52/pym/portage/package/ebuild/doebuild.py --- portage-2.2.0_alpha52-orig/pym/portage/package/ebuild/doebuild.py 2011-09-04 11:45:59 +0900 +++ portage-2.2.0_alpha52/pym/portage/package/ebuild/doebuild.py 2011-09-04 11:48:38 +0900 @@ -931,6 +931,15 @@ if not os.access(parent_dir, os.W_OK): raise PermissionDenied( "access('%s', os.W_OK)" % parent_dir) + # FIXME: doesn't work anymore (this all seems to be handled by the _emerge module now) + #if mydo=="install" and "concise-progress" in mysettings.features: + # timingfile = os.path.join( + # mysettings["PORTAGE_TIMINGDIR"], mysettings["PN"]) + # writemsg(">>> Building %s...\n" % mysettings.mycpv) + # retval = portage.timing.timed_spawnebuild(timingfile, + # "install", actionmap, mysettings, debug, + # logfile=logfile, fd_pipes=fd_pipes, returnpid=returnpid) + #else: retval = spawnebuild(mydo, actionmap, mysettings, debug, logfile=logfile, fd_pipes=fd_pipes, returnpid=returnpid) diff -ur portage-2.2.0_alpha52-orig/pym/portage/package/ebuild/fetch.py portage-2.2.0_alpha52/pym/portage/package/ebuild/fetch.py --- portage-2.2.0_alpha52-orig/pym/portage/package/ebuild/fetch.py 2011-08-12 20:43:40 +0900 +++ portage-2.2.0_alpha52/pym/portage/package/ebuild/fetch.py 2011-09-04 11:48:38 +0900 @@ -14,6 +14,7 @@ import stat import sys import tempfile +import time import portage @@ -35,11 +36,12 @@ from portage.localization import _ from portage.locks import lockfile, unlockfile from portage.manifest import Manifest -from portage.output import colorize, EOutput +from portage.output import colorize, EOutput, EProgressBar from portage.util import apply_recursive_permissions, \ apply_secpass_permissions, ensure_dirs, grabdict, shlex_split, \ varexpand, writemsg, writemsg_level, writemsg_stdout from portage.process import spawn +import portage.timing _userpriv_spawn_kwargs = ( ("uid", portage_uid), @@ -48,7 +50,7 @@ ("umask", 0o02), ) -def _spawn_fetch(settings, args, **kwargs): +def _spawn_fetch(settings, args, progress_bar=None, myfile_path=None, fetched_size=0, **kwargs): """ Spawn a process with appropriate settings for fetching, including userfetch and selinux support. @@ -67,6 +69,17 @@ 2 : sys.stdout.fileno(), } + if progress_bar: + # Run asynchronously so we can watch the file progress + kwargs["returnpid"] = True + # Hide stdout/err so we don't disturb the progress bar + try: + fd = os.open("/dev/null", os.O_RDONLY) + kwargs["fd_pipes"][1] = fd + kwargs["fd_pipes"][2] = fd + except OSError as e: + pass + if "userfetch" in settings.features and \ os.getuid() == 0 and portage_gid and portage_uid: kwargs.update(_userpriv_spawn_kwargs) @@ -94,6 +107,31 @@ else: settings['EBUILD_PHASE'] = phase_backup + if progress_bar: + # Wait for the process to complete, updating the + # file size as we go + mypid = rval[-1] + while mypid != 0: + # Check for process completion (do this first, + # so we get the final file size + rval = os.waitpid(mypid, os.WNOHANG) + if rval[0] == mypid: + mypid = 0 + # Update the progress bar with the current file size + try: + filesize = os.stat(myfile_path).st_size; + progress_bar.update(fetched_size + filesize) + except EnvironmentError: + pass + # Wait a bit so we don't sit on the CPU too much + time.sleep(0.1) + portage.process.spawned_pids.remove(rval[0]) + rval = rval[1] + if rval != os.EX_OK: + if rval & 0xff: + rval = (rval & 0xff) << 8 + rval = rval >> 8 + return rval _userpriv_test_write_file_cache = {} @@ -523,14 +561,20 @@ failed_files = set() restrict_fetch_msg = False + concise_progress = "concise-progress" in features + + total_size = 0 # Total size to fetch in bytes, negative = unknown + fetched_size = 0 # Amount fetched so far in bytes + filestatus = {} # Status of each file (see below) + filelocks = {} # Lock for each file for myfile in filedict: """ - fetched status - 0 nonexistent - 1 partially downloaded - 2 completely downloaded + filestatus + 0 = nonexistent + 1 = partially downloaded + 2 = completely downloaded """ - fetched = 0 + filestatus[myfile] = 0 orig_digests = mydigests.get(myfile, {}) @@ -574,7 +618,7 @@ myfile_path = os.path.join(mysettings["DISTDIR"], myfile) has_space = True has_space_superuser = True - file_lock = None + filelocks[myfile] = None if listonly: writemsg_stdout("\n", noiselevel=-1) else: @@ -631,18 +675,19 @@ lock_kwargs["flags"] = os.O_NONBLOCK try: - file_lock = lockfile(myfile_path, + filelocks[myfile] = lockfile(myfile_path, wantnewlockfile=1, **lock_kwargs) except TryAgain: writemsg(_(">>> File '%s' is already locked by " "another fetcher. Continuing...\n") % myfile, noiselevel=-1) continue - try: - if not listonly: + + if not listonly: # no longer needed, but left in to avoid unindentation creating huge diffs --AC eout = EOutput() - eout.quiet = mysettings.get("PORTAGE_QUIET") == "1" + eout.quiet = concise_progress or \ + mysettings.get("PORTAGE_QUIET") == "1" match, mystat = _check_distfile( myfile_path, pruned_digests, eout) if match: @@ -656,6 +701,7 @@ writemsg(_("!!! Failed to adjust permissions:" " %s\n") % str(e), noiselevel=-1) del e + filestatus[myfile] = 2 continue if distdir_writable and mystat is None: @@ -725,6 +771,7 @@ raise del e os.symlink(readonly_file, myfile_path) + filestatus[myfile] = 2 continue if fsmirrors and not os.path.exists(myfile_path) and has_space: @@ -739,6 +786,11 @@ raise del e + if myfile not in mydigests: + total_size = -1 # At least one file has an unknown size, so give up on counting + elif total_size >= 0: + total_size += mydigests[myfile]["size"]; + try: mystat = os.stat(myfile_path) except OSError as e: @@ -770,11 +822,12 @@ else: if mystat.st_size < mydigests[myfile]["size"] and \ not restrict_fetch: - fetched = 1 # Try to resume this download. + filestatus[myfile] = 1 # Try to resume this download. + fetched_size += mystat.st_size elif parallel_fetchonly and \ mystat.st_size == mydigests[myfile]["size"]: eout = EOutput() - eout.quiet = \ + eout.quiet = concise_progress or \ mysettings.get("PORTAGE_QUIET") == "1" eout.ebegin( "%s size ;-)" % (myfile, )) @@ -802,7 +855,7 @@ temp_filename, noiselevel=-1) else: eout = EOutput() - eout.quiet = \ + eout.quiet = concise_progress or \ mysettings.get("PORTAGE_QUIET", None) == "1" digests = mydigests.get(myfile) if digests: @@ -811,8 +864,26 @@ eout.ebegin( "%s %s ;-)" % (myfile, " ".join(digests))) eout.eend(0) - continue # fetch any remaining files - + if total_size >= 0: + total_size -= mydigests[myfile]["size"] + filestatus[myfile] = 2 # No need to fetch this one + + progress_bar = None + if concise_progress and not listonly and total_size != 0: + progress_bar = EProgressBar(total_size, fetched_size, is_bytes=1) + for myfile in filedict: + myfile_path = os.path.join(mysettings["DISTDIR"], myfile) + if progress_bar: + # If it's a partially-completed file, the file size will be + # already included in fetched_size. Show the progress bar + # as is, then remove this file's contribution (since we'll + # add it back in later on). + progress_bar.update(fetched_size) + try: + fetched_size -= os.stat(myfile_path).st_size; + except EnvironmentError: + pass + try: # Create a reversed list since that is optimal for list.pop(). uri_list = filedict[myfile][:] uri_list.reverse() @@ -885,7 +956,9 @@ return 0 if not can_fetch: - if fetched != 2: + if filestatus[myfile] != 2: + if progress_bar: + progress_bar.finish() try: mysize = os.stat(myfile_path).st_size except OSError as e: @@ -907,16 +980,16 @@ else: continue - if fetched != 2 and has_space: + if filestatus[myfile] != 2 and has_space: #we either need to resume or start the download - if fetched == 1: + if filestatus[myfile] == 1: try: mystat = os.stat(myfile_path) except OSError as e: if e.errno not in (errno.ENOENT, errno.ESTALE): raise del e - fetched = 0 + filestatus[myfile] = 0 else: if mystat.st_size < fetch_resume_size: writemsg(_(">>> Deleting distfile with size " @@ -929,18 +1002,20 @@ (errno.ENOENT, errno.ESTALE): raise del e - fetched = 0 - if fetched == 1: + filestatus[myfile] = 0 + if filestatus[myfile] == 1: #resume mode: - writemsg(_(">>> Resuming download...\n")) + if not progress_bar: + writemsg(">>> Resuming download...\n") locfetch=resumecommand command_var = resumecommand_var else: #normal mode: locfetch=fetchcommand command_var = fetchcommand_var - writemsg_stdout(_(">>> Downloading '%s'\n") % \ - re.sub(r'//(.+):.+@(.+)/',r'//\1:*password*@\2/', loc)) + if not progress_bar: + writemsg_stdout(">>> Downloading '%s'\n" % \ + re.sub(r'//(.+):.+@(.+)/',r'//\1:*password*@\2/', loc)) variables = { "DISTDIR": mysettings["DISTDIR"], "URI": loc, @@ -952,7 +1027,7 @@ myret = -1 try: - myret = _spawn_fetch(mysettings, myfetch) + myret = _spawn_fetch(mysettings, myfetch, progress_bar, myfile_path, fetched_size) finally: try: @@ -962,6 +1037,8 @@ pass except PortageException as e: if not os.access(myfile_path, os.R_OK): + if progress_bar: + progress_bar.finish() writemsg(_("!!! Failed to adjust permissions:" " %s\n") % str(e), noiselevel=-1) del e @@ -972,7 +1049,7 @@ try: if os.stat(myfile_path).st_size == 0: os.unlink(myfile_path) - fetched = 0 + filestatus[myfile] = 0 continue except EnvironmentError: pass @@ -984,7 +1061,7 @@ if e.errno not in (errno.ENOENT, errno.ESTALE): raise del e - fetched = 0 + filestatus[myfile] = 0 else: if stat.S_ISDIR(mystat.st_mode): @@ -1027,11 +1104,11 @@ try: os.unlink(mysettings["DISTDIR"]+"/"+myfile) writemsg(_(">>> Deleting invalid distfile. (Improper 404 redirect from server.)\n")) - fetched = 0 + filestatus[myfile] = 0 continue except (IOError, OSError): pass - fetched = 1 + filestatus[myfile] = 1 continue if True: # File is the correct size--check the checksums for the fetched @@ -1040,6 +1117,8 @@ # from another mirror... verified_ok,reason = verify_all(mysettings["DISTDIR"]+"/"+myfile, mydigests[myfile]) if not verified_ok: + if progress_bar: + progress_bar.finish() print(reason) writemsg(_("!!! Fetched file: %s VERIFY FAILED!\n") % myfile, noiselevel=-1) @@ -1055,7 +1134,7 @@ writemsg_stdout(_("Refetching... " "File renamed to '%s'\n\n") % \ temp_filename, noiselevel=-1) - fetched=0 + filestatus[myfile] = 0 checksum_failure_count += 1 if checksum_failure_count == \ checksum_failure_primaryuri: @@ -1072,29 +1151,35 @@ break else: eout = EOutput() - eout.quiet = mysettings.get("PORTAGE_QUIET", None) == "1" + eout.quiet = progress_bar or \ + mysettings.get("PORTAGE_QUIET", None) == "1" digests = mydigests.get(myfile) if digests: eout.ebegin("%s %s ;-)" % \ (myfile, " ".join(sorted(digests)))) eout.eend(0) - fetched=2 + filestatus[myfile] = 2 break else: if not myret: - fetched=2 + filestatus[myfile] = 2 break elif mydigests!=None: writemsg(_("No digest file available and download failed.\n\n"), noiselevel=-1) finally: - if use_locks and file_lock: - unlockfile(file_lock) - file_lock = None + if use_locks and filelocks[myfile]: + unlockfile(filelocks[myfile]) + filelocks[myfile] = None if listonly: writemsg_stdout("\n", noiselevel=-1) - if fetched != 2: + if progress_bar: + # Save the final progress from this file + fetched_size = progress_bar.progress; + if filestatus[myfile] != 2: + if progress_bar: + progress_bar.finish() if restrict_fetch and not restrict_fetch_msg: restrict_fetch_msg = True msg = _("\n!!! %s/%s" @@ -1126,4 +1211,8 @@ return 0 if failed_files: return 0 + + if progress_bar: + progress_bar.finish() + return 1 diff -urN portage-2.2.0_alpha36-orig/pym/portage/timing.py portage-2.2.0_alpha36/pym/portage/timing.py --- portage-2.2.0_alpha36-orig/pym/portage/timing.py 1970-01-01 09:00:00 +0900 +++ portage-2.2.0_alpha36/pym/portage/timing.py 2011-05-26 19:36:22 +0900 @@ -0,0 +1,330 @@ +# portage_timing.py -- routines to time build execution +# Written by Andrew Church +# This source code is public domain. + +import os, re, select, sys, time +import portage +portage.proxy.lazyimport.lazyimport(globals(), + 'portage.util:writemsg', 'portage.util:writemsg_stdout', + 'portage.versions:pkgsplit', 'output', +) + + +# Output recorded from the current build: +timing_output = [] +# Time at which each line in timing_output[] was recorded: +timing_outtimes = [] +# Current position in timing_{output,times}[]: (to avoid having to extend +# the array every time a new element is added) +timing_outpos = 0 + + +def read_timing(timingfile): + """ + Read a possibly compressed timing file, returning the timing template + as an array of 3-element arrays: the first element of each subarray is + the elapsed time in microseconds between that line and the next, the + second element is the line itself as a string (with no trailing + newline), and the third is the completion fraction at the time the line + is first seen. The timing template array is terminated by an entry + whose first (time) element is the total execution time in microseconds, + whose third (fraction) element is 1.0, and whose remaining elements are + undefined. + + @param timingfile Full pathname of the timing file, without any + compression extension. + @type timingfile String + """ + try: + f = open(timingfile, "r") + timing = [] + for line in f: + timestamp, command = line.split(" ", 1) + command = command.strip("\n") + timing.append([int(timestamp), command, 0.0]) + f.close() + total = 0 + for entry in timing: + entry[2] = (total * 1.0) / timing[-1][0] + total += entry[0] + return timing + except EnvironmentError: + # FIXME: compression not handled at present + return None + + +def write_timing(timingfile): + """ + Write a new timing file from the timing_output[] and timing_outtimes[] + arrays. + + @param timingfile Full pathname of the timing file, without any + compression extension. + @type timingfile String + """ + + try: + timing_outtimes.append(None) # just in case + timing_outtimes[timing_outpos] = time.time() + f = open(timingfile, "w") + total = 0 + for i in range(0, timing_outpos): + line_time = int((timing_outtimes[i+1] - timing_outtimes[i]) * 1000000) + f.write("%u %s\n" % (line_time, timing_output[i])) + total += line_time + f.write("%u -\n" % total) + f.close() + # FIXME: compression not handled at present + except EnvironmentError: + pass + + +def timed_spawnebuild(timingfile, mydo, actionmap, mysettings, debug, + alwaysdep=0, logfile=None, fd_pipes=None, returnpid=False): + """ + Call spawnebuild() in a subprocess, comparing the output to a template + file to display a progress bar instead of the raw output (if the + template file is unavailable, the raw output is shown). If the + operation succeeds, the output and timing information is recorded in + the same template file for future reference. + + @param timingfile Full pathname of the timing file, without any + compression extension. + @type timingfile String + + The remaining parameters are as for spawnebuild(). + """ + + # Read in the timing file, if it exists, and initialize the template + # index. + timing = read_timing(timingfile) + timing_index = -1 + + # Allocate a pseudo-TTY for reading output from the subprocess. If we + # can't, just give up and run the build normally. + master_fd = None + slave_fd = None + from pty import openpty + try: + master_fd, slave_fd = openpty() + except EnvironmentError as e: + writemsg("openpty failed: '%s'\n" % str(e), noiselevel=1) + del e + return portage.spawnebuild(mydo, actionmap, mysettings, debug, + alwaysdep, logfile, fd_pipes, returnpid) + + # Run spawnebuild() in a subprocess, with output redirected to our + # pseudo-TTY. + pid = os.fork() + if pid == 0: + os.close(0) + try: + null_fd = os.open("/dev/null", os.O_RDONLY) + if null_fd != 0: + os.dup2(null_fd, 0) + os.close(null_fd) + except EnvironmentError: + pass + os.dup2(slave_fd, 1) + os.dup2(slave_fd, 2) + os.close(master_fd) + os.close(slave_fd) + retval = portage.spawnebuild(mydo, actionmap, mysettings, debug, + alwaysdep, logfile) + sys.exit(retval) + else: + os.close(slave_fd) + import fcntl + fcntl.fcntl(master_fd, fcntl.F_SETFL, + fcntl.fcntl(master_fd, fcntl.F_GETFL) | os.O_NONBLOCK) + + # Set up a progress bar if we have a timing template. + progress_bar = None + if timing: + progress_bar = output.EProgressBar(timing[-1][0]) + progress_bar.update(0) + last_update = time.time() + + # Clear the new timing data. + global timing_output, timing_outtimes, timing_outpos + timing_output = [] + timing_outtimes = [] + timing_outpos = 0 + + # Read output from the subprocess until it completes, updating the new + # timing template for each line read. + master_file = os.fdopen(master_fd, "r") + saved_line = "" # In case we only get a partial line when reading + eof = False # Becomes true when we get an EOF from the pseudo-TTY + finished = False # Becomes true when the subprocess exits + result = None # Result code from the subprocess + while not finished or not eof: + # Check for subprocess completion. + waitres = os.waitpid(pid, os.WNOHANG) + if waitres and waitres[0] == pid: + finished = True + if waitres[1] == os.EX_OK: + result = os.EX_OK + elif waitres[1] & 0xFF: + result = (waitres[1] & 0xFF) << 8 + else: + result = waitres[1] >> 8 + # Check for build output. + events = select.select([master_file], [], [], 0.1) + if events: + s = None + try: + s = master_file.read(1000) + except IOError: + eof = True + if s is None: + if len(saved_line) > 0: + # The final line didn't end with a newline, so add one. + s = "\n" + s = "" + eof = True + elif s == "": + break # No more output this time around + saved_line += s + now = time.time() + index = saved_line.find("\n") + while index >= 0: + line = saved_line[0:index] + saved_line = saved_line[index+1:] + timing_index = add_line(line, timing, timing_index, \ + master_file, mysettings) + if not timing: + writemsg_stdout("%s\n" % line); + index = saved_line.find("\n") + # Update the progress bar (but not too frequently). + if timing and now - last_update >= 0.01: + # Calculate the rate at which we're progressing relative to the + # data recorded in the template. + rate = 0 + if timing_index >= 0 and timing_outpos > 0 \ + and timing[timing_index][2] > 0: + rate = (timing_outtimes[timing_outpos-1] - timing_outtimes[0]) \ + / (timing[-1][0]/1000000.0 * timing[timing_index][2]) + # Calculate the percentage complete, including partial processing + # for the current line. + pct = 0 + if timing_index >= 0: + pct = timing[timing_index][2] + if rate > 0 and now > timing_outtimes[timing_outpos-1]: + extra_time = now - timing_outtimes[timing_outpos-1] + extra_pct = (extra_time / rate) / (timing[-1][0] / 1000000.0) + if extra_pct > timing[timing_index+1][2] - pct: + extra_pct = timing[timing_index+1][2] - pct + pct += extra_pct + # Update the progress bar, making sure it uses our idea of the + # starting time. + if timing_outpos > 0: + progress_bar.start_time = timing_outtimes[0] + progress_bar.update(int(timing[-1][0] * pct)) + # Save the last update time to avoid over-frequent updates. + last_update = now + # while not finished + + # Finish off the progress bar. + if timing: + progress_bar.progress = progress_bar.total + progress_bar.finish() + + # Write out the new timing data + if result == os.EX_OK: + write_timing(timingfile) + + # Return the build result + return result + + +# Variables used by add_line: +search_last = 0 +search_wait = 0 +search_max = 0 + +def add_line(line, timing, timing_index, master_file, mysettings): + """ + Process a line of output from the build subprocess. + + @param line: The line of text, without any trailing newline. + @type line: String + @param timing: The timing template, or None if not available. + @type timing: Array + @param timing_index: The current index into the timing template. + @type timing_index: Integer + @param master_file: Pseudo-TTY from which build output is read. + @type master_file: Filehandle + @param mysettings: Portage configuration. + @type mysettings: Instance of portage.config + @returns The new timing index, or 0 if no template is available. + """ + + global timing_output, timing_outtimes, timing_outpos + + now = time.time() + + # First, append the line to the output arrays. Massage the line a bit + # so that changes in version number, compilation options and the like + # don't cause mismatches later on. + package, version = pkgsplit(mysettings.mycpv.split("/",1)[1])[0:2] + line = re.sub(r'\s+', r' ', line) + line = line.replace(package+'-'+version, package+'-VER') + line = re.sub(r'(^|\W)(cc|gcc|xgcc|gcc3|icc)(\W)', r'\1CC\3', line) + line = re.sub(r'(^|\W)(c\+\+|g\+\+|g\+\+3)(\W)', r'\1CXX\3', line) + if re.match(r'^\s*(cd\s+\S+\s*;\s*)?(if\s+)?(stage\d\/)?(CC|CXX)[^=]', line): + line = re.sub(r'(\s+-(-\S+|[^-\s]\S*))+', r' -OPTS', line) + if timing_outpos >= len(timing_output): + # Extend the arrays in big jumps for efficiency + timing_output.append([None]*1000) + timing_outtimes.append([None]*1000) + timing_output[timing_outpos] = line + timing_outtimes[timing_outpos] = now + timing_outpos += 1 + + # Now look for a matching line in the template (if we don't have a + # template, just return 0). + if not timing: + return 0 + global search_last # Time of last search + global search_wait # Time in seconds to wait before the next search + global search_max # Maximum time in seconds to search + # If the next line matches, use it. + if timing[timing_index+1][1] == line: + search_wait = 0 + search_max = 0.05 + return timing_index+1 + # Otherwise we have to search. But don't do so on every line, or we + # could eat huge amounts of CPU time if the build output differs from + # the template. + if time.time() - search_last < search_wait: + return timing_index + # Search forward for a matching line until we hit our time limit, but + # don't keep the build process waiting if it has more output for us. + found = False + got_output = False + search_limit = time.time() + search_max + index = timing_index + 2 + while index < len(timing)-1 and time.time() - search_limit: + if timing[index][1] == line: + found = True + break + if not got_output and select.select([master_file], [], [], 0): + got_output = True + search_limit = time.time() + 0.01 + index += 1 + # Save the time this search ended. + search_last = time.time() + # If we found a match, return it; otherwise try harder next time. + if found: + search_wait = 0; + search_max = 0.05; + return index + else: + search_wait += 0.05 + if search_wait > 3: + search_wait = 3 + search_max += 0.05 + if search_wait > 1: + search_wait = 1 + return timing_index