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))
