def logForOutcome(decider): for cycle in self.results: cyclestr = '' if len(self.results) > 1: cyclestr = '[CYCLE %d] ' % (cycle + 1) for outcome in OUTCOMES: if not decider(outcome): continue # sort similar outcomes together to make the results easier to read; by reason then testDir self.results[cycle][outcome].sort( key=lambda test: [test[1], test[3]]) for (id, reason, testTitle, testDir, outputdir) in self.results[cycle][outcome]: log(" %s%s: %s ", cyclestr, outcome, id, extra=ColorLogFormatter.tag(str(outcome).lower())) if showTestTitle and testTitle: log(" (title: %s)", testTitle, extra=ColorLogFormatter.tag(LOG_DEBUG)) if showOutcomeReason and reason: log(" %s", reason, extra=ColorLogFormatter.tag(LOG_TEST_OUTCOMES)) try: outputdir = os.path.normpath( os.path.relpath( fromLongPathSafe(outputdir))) + os.sep testDir = os.path.normpath( os.path.relpath( fromLongPathSafe(testDir))) + os.sep except Exception as ex: # relpath can fail if on different Windows drives logging.getLogger('pysys.writer').debug( 'Failed to generate relative paths for "%s" and "%s": %s', outputdir, testDir, ex) if showTestDir and not (showOutputDir and outputdir.startswith(testDir)): # don't confuse things by showing the testDir unless its information is not present in the outputDir (due to --outdir) log(" %s", testDir) if showOutputDir: log(" %s", outputdir)
def processResult(self, testObj, cycle=-1, **kwargs): if self.numTests == 1: return log = logging.getLogger('pysys.resultsprogress') id = self.testToDisplay(testObj, cycle) self.inprogress.remove(id) outcome = testObj.getOutcome() self.outcomes[outcome] += 1 executed = sum(self.outcomes.values()) if outcome.isFailure(): m = '%s: %s' % (outcome, id) if testObj.getOutcomeReason(): m += ': ' + testObj.getOutcomeReason() self._recentFailureReasons.append(m) self._recentFailureReasons = self._recentFailureReasons[ -1 * self.recentFailures:] # keep last N # nb: no need to lock since this always executes on the main thread timediv = 1 if time.time() - self.startTime > 60: timediv = 60 log.info('Test progress: %s = %s of tests in %d %s', ('completed %d/%d' % (executed, self.numTests)), '%0.1f%%' % (100.0 * executed / self.numTests), int((time.time() - self.startTime) / timediv), 'seconds' if timediv == 1 else 'minutes', extra=ColorLogFormatter.tag(LOG_TEST_PROGRESS, [0, 1])) failednumber = sum( [self.outcomes[o] for o in OUTCOMES if o.isFailure()]) passed = ', '.join([ '%d %s' % (self.outcomes[o], o) for o in OUTCOMES if not o.isFailure() and self.outcomes[o] > 0 ]) failed = ', '.join([ '%d %s' % (self.outcomes[o], o) for o in OUTCOMES if o.isFailure() and self.outcomes[o] > 0 ]) if passed: log.info(' %s (%0.1f%%)', passed, 100.0 * (executed - failednumber) / executed, extra=ColorLogFormatter.tag(LOG_PASSES)) if failed: log.info(' %s', failed, extra=ColorLogFormatter.tag(LOG_FAILURES)) if self._recentFailureReasons: log.info('Recent failures: ', extra=ColorLogFormatter.tag(LOG_TEST_PROGRESS)) for f in self._recentFailureReasons: log.info(' ' + f, extra=ColorLogFormatter.tag(LOG_FAILURES)) inprogress = list(self.inprogress) if self.threads > 1 and inprogress: log.info('Currently executing: %s', ', '.join(sorted(inprogress)), extra=ColorLogFormatter.tag(LOG_TEST_PROGRESS)) log.info('')
def printNonPassesSummary(self, log): showOutcomeReason = str(self.showOutcomeReason).lower() == 'true' showOutputDir = str(self.showOutputDir).lower() == 'true' log.critical("Summary of non passes: ") fails = 0 for cycle in list(self.results.keys()): for outcome in list(self.results[cycle].keys()): if outcome in FAILS : fails = fails + len(self.results[cycle][outcome]) if fails == 0: log.critical(" THERE WERE NO NON PASSES", extra=ColorLogFormatter.tag(LOG_PASSES)) else: for cycle in list(self.results.keys()): cyclestr = '' if len(self.results) > 1: cyclestr = '[CYCLE %d] '%(cycle+1) for outcome in FAILS: for (id, reason, outputdir) in self.results[cycle][outcome]: log.critical(" %s%s: %s ", cyclestr, LOOKUP[outcome], id, extra=ColorLogFormatter.tag(LOOKUP[outcome].lower())) if showOutputDir: log.critical(" %s", os.path.normpath(os.path.relpath(outputdir))) if showOutcomeReason and reason: log.critical(" %s", reason, extra=ColorLogFormatter.tag(LOG_TEST_OUTCOMES))
def logForOutcome(decider): for cycle in self.results: cyclestr = '' if len(self.results) > 1: cyclestr = '[CYCLE %d] ' % (cycle + 1) for outcome in OUTCOMES: if not decider(outcome): continue # sort similar outcomes together to make the results easier to read; by reason then testDir self.results[cycle][outcome].sort( key=lambda test: [test[1], test[3]]) for (id, reason, testTitle, testDir, outputdir) in self.results[cycle][outcome]: log(" %s%s: %s ", cyclestr, outcome, id, extra=ColorLogFormatter.tag(str(outcome).lower())) if showTestTitle and testTitle: log(" (title: %s)", testTitle, extra=ColorLogFormatter.tag(LOG_DEBUG)) if showOutcomeReason and reason: log(" %s", reason, extra=ColorLogFormatter.tag(LOG_TEST_OUTCOMES)) outputdir = os.path.normpath( os.path.relpath(outputdir)) + os.sep testDir = os.path.normpath( os.path.relpath(testDir)) + os.sep if showTestDir and not (showOutputDir and outputdir.startswith(testDir)): # don't confuse things by showing the testDir unless its information is not present in the outputDir (due to --outdir) log(" %s", testDir) if showOutputDir: log(" %s", outputdir)
def logSummary(self, log, showDuration=None, showOutcomeStats=None, showTestIdList=None, showFailureSummary=True, showRunDetails=None, **kwargs): """ Writes a textual summary using the specified log function, with colored output if enabled. The keyword arguments can be used to disable sections of the output (overriding the settings) if needed by the caller. :param Callable[format,args,kwargs=] log: The function to call for each line of the summary (e.g. log.critical). The message is obtained with ``format % args``, and color information is available from the ``extra=`` keyword argument. """ assert not kwargs, kwargs.keys() if showDuration is None: showDuration = self.showDuration and self.numTests > 1 if showOutcomeStats is None: showOutcomeStats = self.showOutcomeStats and self.numTests > 1 if showTestIdList is None: showTestIdList = self.showTestIdList and self.numTests > 1 if showRunDetails is None: showRunDetails = self.showRunDetails and self.numTests > 1 # details from showFailureSummary: showOutcomeReason = self.showOutcomeReason showOutputDir = self.showOutputDir showTestDir = self.showTestDir showTestTitle = self.showTestTitle showInspectSummary = self.showInspectSummary showNotVerifiedSummary = self.showNotVerifiedSummary if showDuration: log("Completed test run at: %s", time.strftime('%A %Y-%m-%d %H:%M:%S %Z', time.localtime(time.time())), extra=ColorLogFormatter.tag(LOG_DEBUG, 0)) if self.threads > 1: log("Total test duration (absolute): %s", '%.2f secs' % (time.time() - self.startTime), extra=ColorLogFormatter.tag(LOG_DEBUG, 0)) log("Total test duration (additive): %s", '%.2f secs' % self.duration, extra=ColorLogFormatter.tag(LOG_DEBUG, 0)) else: log("Total test duration: %s", "%.2f secs" % (time.time() - self.startTime), extra=ColorLogFormatter.tag(LOG_DEBUG, 0)) log('') if showRunDetails: log("Run details:") for k, v in self.runner.runDetails.items(): log(" %23s%s", k + ': ', v, extra=ColorLogFormatter.tag(LOG_TEST_DETAILS, 1)) log("") if showOutcomeStats: executed = sum(self.outcomes.values()) failednumber = sum( [self.outcomes[o] for o in OUTCOMES if o.isFailure()]) passed = ', '.join([ '%d %s' % (self.outcomes[o], o) for o in OUTCOMES if not o.isFailure() and self.outcomes[o] > 0 ]) failed = ', '.join([ '%d %s' % (self.outcomes[o], o) for o in OUTCOMES if o.isFailure() and self.outcomes[o] > 0 ]) if failed: log('Failure outcomes: %s (%0.1f%%)', failed, 100.0 * (failednumber) / executed, extra=ColorLogFormatter.tag(str(FAILED).lower(), [0])) if passed: log('Success outcomes: %s', passed, extra=ColorLogFormatter.tag(str(PASSED).lower(), [0])) log('') def logForOutcome(decider): for cycle in self.results: cyclestr = '' if len(self.results) > 1: cyclestr = '[CYCLE %d] ' % (cycle + 1) for outcome in OUTCOMES: if not decider(outcome): continue # sort similar outcomes together to make the results easier to read; by reason then testDir self.results[cycle][outcome].sort( key=lambda test: [test[1], test[3]]) for (id, reason, testTitle, testDir, outputdir) in self.results[cycle][outcome]: log(" %s%s: %s ", cyclestr, outcome, id, extra=ColorLogFormatter.tag(str(outcome).lower())) if showTestTitle and testTitle: log(" (title: %s)", testTitle, extra=ColorLogFormatter.tag(LOG_DEBUG)) if showOutcomeReason and reason: log(" %s", reason, extra=ColorLogFormatter.tag(LOG_TEST_OUTCOMES)) outputdir = os.path.normpath( os.path.relpath(outputdir)) + os.sep testDir = os.path.normpath( os.path.relpath(testDir)) + os.sep if showTestDir and not (showOutputDir and outputdir.startswith(testDir)): # don't confuse things by showing the testDir unless its information is not present in the outputDir (due to --outdir) log(" %s", testDir) if showOutputDir: log(" %s", outputdir) if showNotVerifiedSummary and self.outcomes[NOTVERIFIED] > 0: log("Summary of not verified outcomes:") logForOutcome(lambda outcome: outcome == NOTVERIFIED) log('') if showInspectSummary and self.outcomes[INSPECT] > 0: log("Summary of inspect outcomes: ") logForOutcome(lambda outcome: outcome == INSPECT) log('') if showFailureSummary: log("Summary of failures: ") fails = 0 for cycle in self.results: for outcome, tests in self.results[cycle].items(): if outcome.isFailure(): fails = fails + len(tests) if fails == 0: log(" THERE WERE NO FAILURES", extra=ColorLogFormatter.tag(LOG_PASSES)) else: logForOutcome(lambda outcome: outcome.isFailure()) log('') if showTestIdList: failedids = [] failedidsAlreadyDone = set() for cycle in self.results: for outcome in OUTCOMES: if not outcome.isFailure(): continue for (id, reason, testTitle, testDir, outputdir) in self.results[cycle][outcome]: if id in failedidsAlreadyDone: continue failedidsAlreadyDone.add(id) failedids.append(id) if len(failedids) > 1: # display just the ids, in a way that's easy to copy and paste into a command line; # for maximum usability, use the sort order given above failedids = failedids if len( failedids ) > 100: # this feature is only useful for small test runs failedids = failedids[:100] + ['...'] log('List of failed test ids:') log('%s', ' '.join(failedids))
def logSummary(self, log, showDuration=None, showOutcomeStats=None, showOutcomeReason=None, showOutputDir=None, showTestIdList=None, **kwargs): """ Writes a textual summary using the specified log function, with colored output if enabled. :param Callable[format,args,kwargs=] log: The function to call for each line of the summary (e.g. log.critical). The message is obtained with ``format % args``, and color information is available from the ``extra=`` keyword argument. """ assert not kwargs, kwargs.keys() if showDuration is None: showDuration = str(self.showDuration).lower() == 'true' if showOutcomeStats is None: showOutcomeStats = str(self.showOutcomeStats).lower() == 'true' if showOutcomeReason is None: showOutcomeReason = str(self.showOutcomeReason).lower() == 'true' if showOutputDir is None: showOutputDir = str(self.showOutputDir).lower() == 'true' if showTestIdList is None: showTestIdList = str(self.showTestIdList).lower() == 'true' if showDuration: log( "Completed test run at: %s", time.strftime('%A %Y-%m-%d %H:%M:%S %Z', time.localtime(time.time())), extra=ColorLogFormatter.tag(LOG_DEBUG, 0)) if self.threads > 1: log("Total test duration (absolute): %s", '%.2f secs'%(time.time() - self.startTime), extra=ColorLogFormatter.tag(LOG_DEBUG, 0)) log("Total test duration (additive): %s", '%.2f secs'%self.duration, extra=ColorLogFormatter.tag(LOG_DEBUG, 0)) else: log("Total test duration: %s", "%.2f secs"%(time.time() - self.startTime), extra=ColorLogFormatter.tag(LOG_DEBUG, 0)) log('') if showOutcomeStats: executed = sum(self.outcomes.values()) failednumber = sum([self.outcomes[o] for o in FAILS]) passed = ', '.join(['%d %s'%(self.outcomes[o], LOOKUP[o]) for o in PRECEDENT if o not in FAILS and self.outcomes[o]>0]) failed = ', '.join(['%d %s'%(self.outcomes[o], LOOKUP[o]) for o in PRECEDENT if o in FAILS and self.outcomes[o]>0]) if failed: log('Failure outcomes: %s (%0.1f%%)', failed, 100.0 * (failednumber) / executed, extra=ColorLogFormatter.tag(LOOKUP[FAILED].lower(), [0,1])) if passed: log('Success outcomes: %s', passed, extra=ColorLogFormatter.tag(LOOKUP[PASSED].lower(), [0])) log('') log("Summary of failures: ") fails = 0 for cycle in self.results: for outcome, tests in self.results[cycle].items(): if outcome in FAILS : fails = fails + len(tests) if fails == 0: log(" THERE WERE NO FAILURES", extra=ColorLogFormatter.tag(LOG_PASSES)) else: failedids = set() for cycle in self.results: cyclestr = '' if len(self.results) > 1: cyclestr = '[CYCLE %d] '%(cycle+1) for outcome in FAILS: for (id, reason, outputdir) in self.results[cycle][outcome]: failedids.add(id) log(" %s%s: %s ", cyclestr, LOOKUP[outcome], id, extra=ColorLogFormatter.tag(LOOKUP[outcome].lower())) if showOutputDir: log(" %s", os.path.normpath(os.path.relpath(outputdir))+os.sep) if showOutcomeReason and reason: log(" %s", reason, extra=ColorLogFormatter.tag(LOG_TEST_OUTCOMES)) if showTestIdList and len(failedids) > 1: # display just the ids, in a way that's easy to copy and paste into a command line failedids = list(failedids) failedids.sort() if len(failedids) > 20: # this feature is only useful for small test runs failedids = failedids[:20]+['...'] log('') log('List of failed test ids:') log('%s', ' '.join(failedids))