X-Git-Url: https://git.distorted.org.uk/~mdw/stgit/blobdiff_plain/7748ec707072ac014a106bdb56f8517d1f9a8915..79473ca5521ec3233dcf83d1c25758cf5eff7386:/stgit/run.py diff --git a/stgit/run.py b/stgit/run.py index ae3a2e1..2d8ed34 100644 --- a/stgit/run.py +++ b/stgit/run.py @@ -17,26 +17,50 @@ along with this program; if not, write to the Free Software Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA """ -# popen2 and os.spawn* suck. We should really use subprocess instead, -# but that's only available in Python 2.4 and up, and we try our best -# to stay Python 2.3 compatible. -import popen2, os +import datetime, os, subprocess -import datetime +from stgit.exception import * +from stgit.out import * -from stgit.out import * - -class RunException(Exception): +class RunException(StgException): """Thrown when something bad happened when we tried to run the subprocess.""" pass -_all_log_modes = ['debug', 'profile'] -_log_mode = os.environ.get('STGIT_SUBPROCESS_LOG', '') -if _log_mode and not _log_mode in _all_log_modes: - out.warn(('Unknown log mode "%s" specified in $STGIT_SUBPROCESS_LOG.' - % _log_mode), - 'Valid values are: %s' % ', '.join(_all_log_modes)) +def get_log_mode(spec): + if not ':' in spec: + spec += ':' + (log_mode, outfile) = spec.split(':', 1) + all_log_modes = ['debug', 'profile'] + if log_mode and not log_mode in all_log_modes: + out.warn(('Unknown log mode "%s" specified in $STGIT_SUBPROCESS_LOG.' + % log_mode), + 'Valid values are: %s' % ', '.join(all_log_modes)) + if outfile: + f = MessagePrinter(open(outfile, 'a')) + else: + f = out + return (log_mode, f) + +(_log_mode, _logfile) = get_log_mode(os.environ.get('STGIT_SUBPROCESS_LOG', '')) +if _log_mode == 'profile': + _log_starttime = datetime.datetime.now() + _log_subproctime = 0.0 + +def duration(t1, t2): + d = t2 - t1 + return 86400*d.days + d.seconds + 1e-6*d.microseconds + +def finish_logging(): + if _log_mode != 'profile': + return + ttime = duration(_log_starttime, datetime.datetime.now()) + rtime = ttime - _log_subproctime + _logfile.info('Total time: %1.3f s' % ttime, + 'Time spent in subprocess calls: %1.3f s (%1.1f%%)' + % (_log_subproctime, 100*_log_subproctime/ttime), + 'Remaining time: %1.3f s (%1.1f%%)' + % (rtime, 100*rtime/ttime)) class Run: exc = RunException @@ -44,61 +68,87 @@ class Run: self.__cmd = list(cmd) for c in cmd: if type(c) != str: - raise Exception, 'Bad command: %r' % cmd + raise Exception, 'Bad command: %r' % (cmd,) self.__good_retvals = [0] - self.__env = None + self.__env = self.__cwd = None self.__indata = None - def __log_start(self, cmd): + self.__discard_stderr = False + def __log_start(self): if _log_mode == 'debug': - out.start('Running subprocess %s' % cmd) + _logfile.start('Running subprocess %s' % self.__cmd) + if self.__cwd != None: + _logfile.info('cwd: %s' % self.__cwd) + if self.__env != None: + for k in sorted(self.__env.iterkeys()): + if k not in os.environ or os.environ[k] != self.__env[k]: + _logfile.info('%s: %s' % (k, self.__env[k])) elif _log_mode == 'profile': - out.start('Running subprocess %s' % cmd[0]) + _logfile.start('Running subprocess %s' % self.__cmd) self.__starttime = datetime.datetime.now() def __log_end(self, retcode): + global _log_subproctime, _log_starttime if _log_mode == 'debug': - out.done('return code: %d' % retcode) + _logfile.done('return code: %d' % retcode) elif _log_mode == 'profile': - duration = datetime.datetime.now() - self.__starttime - out.done('%1.3f s' % (duration.microseconds/1e6 + duration.seconds)) - def __run_io(self, cmd): - """Run with captured IO. Note: arguments are parsed by the - shell. We single-quote them, so don't use anything with single - quotes in it.""" - if self.__env == None: - ecmd = cmd - else: - ecmd = (['env'] + ['%s=%s' % (key, val) - for key, val in self.__env.iteritems()] - + cmd) - self.__log_start(ecmd) - p = popen2.Popen3(' '.join(["'%s'" % c for c in ecmd]), True) - if self.__indata != None: - p.tochild.write(self.__indata) - p.tochild.close() - outdata = p.fromchild.read() - errdata = p.childerr.read() - self.exitcode = p.wait() >> 8 + n = datetime.datetime.now() + d = duration(self.__starttime, n) + _logfile.done('%1.3f s' % d) + _log_subproctime += d + _logfile.info('Time since program start: %1.3f s' + % duration(_log_starttime, n)) + def __check_exitcode(self): + if self.__good_retvals == None: + return + if self.exitcode not in self.__good_retvals: + raise self.exc('%s failed with code %d' + % (self.__cmd[0], self.exitcode)) + def __run_io(self): + """Run with captured IO.""" + self.__log_start() + try: + p = subprocess.Popen(self.__cmd, env = self.__env, cwd = self.__cwd, + stdin = subprocess.PIPE, + stdout = subprocess.PIPE, + stderr = subprocess.PIPE) + # TODO: only use communicate() once support for Python 2.4 is + # dropped (write() needed because of performance reasons) + if self.__indata: + p.stdin.write(self.__indata) + outdata, errdata = p.communicate() + self.exitcode = p.returncode + except OSError, e: + raise self.exc('%s failed: %s' % (self.__cmd[0], e)) + if errdata and not self.__discard_stderr: + out.err_raw(errdata) self.__log_end(self.exitcode) - if errdata or self.exitcode not in self.__good_retvals: - raise self.exc('%s failed with code %d:\n%s' - % (cmd[0], self.exitcode, errdata)) + self.__check_exitcode() return outdata - def __run_noshell(self, cmd): - """Run without captured IO. Note: arguments are not parsed by - the shell.""" - assert self.__env == None + def __run_noio(self): + """Run without captured IO.""" assert self.__indata == None - self.__log_start(cmd) - self.exitcode = os.spawnvp(os.P_WAIT, cmd[0], cmd) + self.__log_start() + try: + p = subprocess.Popen(self.__cmd, env = self.__env, cwd = self.__cwd) + self.exitcode = p.wait() + except OSError, e: + raise self.exc('%s failed: %s' % (self.__cmd[0], e)) self.__log_end(self.exitcode) - if not self.exitcode in self.__good_retvals: - raise self.exc('%s failed with code %d' - % (cmd[0], self.exitcode)) + self.__check_exitcode() def returns(self, retvals): self.__good_retvals = retvals return self + def discard_exitcode(self): + self.__good_retvals = None + return self + def discard_stderr(self, discard = True): + self.__discard_stderr = discard + return self def env(self, env): - self.__env = env + self.__env = dict(os.environ) + self.__env.update(env) + return self + def cwd(self, cwd): + self.__cwd = cwd return self def raw_input(self, indata): self.__indata = indata @@ -106,16 +156,19 @@ class Run: def input_lines(self, lines): self.__indata = ''.join(['%s\n' % line for line in lines]) return self + def input_nulterm(self, lines): + self.__indata = ''.join('%s\0' % line for line in lines) + return self def no_output(self): - outdata = self.__run_io(self.__cmd) + outdata = self.__run_io() if outdata: raise self.exc, '%s produced output' % self.__cmd[0] def discard_output(self): - self.__run_io(self.__cmd) + self.__run_io() def raw_output(self): - return self.__run_io(self.__cmd) + return self.__run_io() def output_lines(self): - outdata = self.__run_io(self.__cmd) + outdata = self.__run_io() if outdata.endswith('\n'): outdata = outdata[:-1] if outdata: @@ -131,11 +184,14 @@ class Run: % (self.__cmd[0], len(outlines))) def run(self): """Just run, with no IO redirection.""" - self.__run_noshell(self.__cmd) + self.__run_noio() def xargs(self, xargs): """Just run, with no IO redirection. The extra arguments are appended to the command line a few at a time; the command is run as many times as needed to consume them all.""" step = 100 + basecmd = self.__cmd for i in xrange(0, len(xargs), step): - self.__run_noshell(self.__cmd + xargs[i:i+step]) + self.__cmd = basecmd + xargs[i:i+step] + self.__run_noio() + self.__cmd = basecmd