[Piglit] [PATCH 4/4] log: add verbose logger
Dylan Baker
baker.dylan.c at gmail.com
Mon Feb 17 11:45:34 PST 2014
This adds a verbose logger option, similar to that of the old piglit
logger, but with some of the flair of the new one.
Signed-off-by: Dylan Baker <baker.dylan.c at gmail.com>
--
framework/core.py | 17 ++++-----
framework/log.py | 56 +++++++++++++++++++++++-------
framework/tests/log_tests.py | 83 ++++++++++++++++++++++++++++++++------------
piglit-resume.py | 8 +++++
piglit-run.py | 7 +++-
5 files changed, 127 insertions(+), 44 deletions(-)
diff --git a/framework/core.py b/framework/core.py
index 13ed235..761af8e 100644
--- a/framework/core.py
+++ b/framework/core.py
@@ -355,7 +355,7 @@ class TestrunResult:
class Environment:
def __init__(self, concurrent=True, execute=True, include_filter=[],
- exclude_filter=[], valgrind=False, dmesg=False):
+ exclude_filter=[], valgrind=False, dmesg=False, verbose=False):
self.concurrent = concurrent
self.execute = execute
self.filter = []
@@ -363,6 +363,7 @@ class Environment:
self.exclude_tests = set()
self.valgrind = valgrind
self.dmesg = dmesg
+ self.verbose = verbose
"""
The filter lists that are read in should be a list of string objects,
@@ -434,11 +435,10 @@ class Test(object):
``spec/glsl-1.30/preprocessor/compiler/keywords/void.frag``.
'''
- log_current = log.pre_log()
+ log_current = log.pre_log(path if env.concurrent else None)
# Run the test
if env.execute:
try:
- log.log()
time_start = time.time()
dmesg.update_dmesg()
self._test_hook_execute_run()
@@ -462,7 +462,9 @@ class Test(object):
result['traceback'] = \
"".join(traceback.format_tb(sys.exc_info()[2]))
- test_result = result['result']
+ log.log(path, result['result'])
+ log.post_log(log_current, result['result'])
+
if 'subtest' in result and len(result['subtest']) > 1:
for test in result['subtest']:
result['result'] = result['subtest'][test]
@@ -470,9 +472,8 @@ class Test(object):
else:
json_writer.write_dict_item(path, result)
else:
- test_result = 'dry-run'
- log.log()
- log.post_log(log_current, test_result)
+ log.log(path, 'dry-run')
+ log.post_log(log_current, 'dry-run')
class Group(dict):
@@ -557,7 +558,7 @@ class TestProfile(object):
'''
self.prepare_test_list(env)
- log = Log(len(self.test_list))
+ log = Log(len(self.test_list), env.verbose)
def test(pair):
""" Function to call test.execute from .map
diff --git a/framework/log.py b/framework/log.py
index 676d122..a521e79 100644
--- a/framework/log.py
+++ b/framework/log.py
@@ -32,7 +32,7 @@ class Log(object):
total -- The total number of tests to run.
"""
- def __init__(self, total):
+ def __init__(self, total, verbose):
self.__total = total
self.__complete = 0
self.__running = []
@@ -42,17 +42,39 @@ class Log(object):
'dmesg-warn', 'dmesg-fail', 'dry-run'])
self.__summary = collections.defaultdict(lambda: 0)
+ if verbose:
+ self.__output = ("{result} :: {name}\n"
+ "[{percent}] {summary} {running}\r")
+ else:
+ self.__output = "[{percent}] {summary} {running}\r"
+
+
def _summary(self):
+ """ return a summary of the statuses """
return ", ".join("{0}: {1}".format(k, self.__summary[k])
for k in sorted(self.__summary))
def _running(self):
+ """ return running tests """
return "Running Test(s): {}".format(
" ".join([str(x).zfill(self.__pad) for x in self.__running]))
def _percent(self):
- return "[{0}/{1}]".format(str(self.__complete).zfill(self.__pad),
- str(self.__total).zfill(self.__pad))
+ """ return the percentage of tess completed """
+ return "{0}/{1}".format(str(self.__complete).zfill(self.__pad),
+ str(self.__total).zfill(self.__pad))
+
+ def __print(self, name, result):
+ """ Do the actual printing """
+ sys.stdout.write(self.__output.format(**{'percent': self._percent(),
+ 'running': self._running(),
+ 'summary': self._summary(),
+ 'name': name,
+ 'result': result}))
+
+ # Need to flush explicitly, otherwise it all gets buffered without a
+ # newline.
+ sys.stdout.flush()
@synchronized_self
def post_log(self, value, result):
@@ -74,23 +96,31 @@ class Log(object):
self.__summary[result] += 1
@synchronized_self
- def log(self):
+ def log(self, name, result):
""" Print to the screen
Works by moving the cursor back to the front of the line and printing
over it.
-
- """
- sys.stdout.write("{0} {1} {2}\r".format(
- self._percent(), self._summary(), self._running()))
- # Need to flush explicitly, otherwise it all gets buffered without a
- # newline.
- sys.stdout.flush()
+ """
+ assert result in self.__summary_keys
+ self.__print(name, result)
@synchronized_self
- def pre_log(self):
- """ Returns a new number to know what processes are running """
+ def pre_log(self, running=None):
+ """ Hook to run before log()
+
+ Returns a new number to know what processes are running, if running is
+ set it will print a running message for the test
+
+ Keyword Arguments:
+ running -- the name of a test to print is running. If Falsy then
+ nothing will be printed. Default: None
+
+ """
+ if running:
+ self.__print(running, 'running')
+
x = self.__generator.next()
self.__running.append(x)
return x
diff --git a/framework/tests/log_tests.py b/framework/tests/log_tests.py
index 8b817f2..6969fb3 100644
--- a/framework/tests/log_tests.py
+++ b/framework/tests/log_tests.py
@@ -29,15 +29,21 @@ from framework.log import Log
valid_statuses = ('pass', 'fail', 'crash', 'warn', 'dmesg-warn',
'dmesg-fail', 'skip', 'dry-run')
-def test_initialize_log():
- """ Test that Log initializes with """
- log = Log(100)
+def test_initialize_log_terse():
+ """ Test that Log initializes with verbose=False """
+ log = Log(100, False)
+ assert log
+
+
+def test_initialize_log_verbose():
+ """ Test that Log initializes with verbose=True """
+ log = Log(100, True)
assert log
def test_pre_log_return():
""" Test that pre_log returns a number """
- log = Log(100)
+ log = Log(100, False)
ret = log.pre_log()
nt.assert_true(isinstance(ret, (IntType, FloatType, LongType)),
@@ -46,7 +52,7 @@ def test_pre_log_return():
def test_post_log_increment_complete():
""" Tests that Log.post_log() increments self.__complete """
- log = Log(100)
+ log = Log(100, False)
ret = log.pre_log()
log.post_log(ret, 'pass')
nt.assert_equal(log._Log__complete, 1,
@@ -56,7 +62,7 @@ def test_post_log_increment_complete():
def check_post_log_increment_summary(stat):
""" Test that passing a result to post_log works correctly """
- log = Log(100)
+ log = Log(100, False)
ret = log.pre_log()
log.post_log(ret, stat)
print log._Log__summary
@@ -77,7 +83,7 @@ def test_post_log_increment_summary():
def test_post_log_removes_complete():
""" Test that Log.post_log() removes finished tests from __running """
- log = Log(100)
+ log = Log(100, False)
ret = log.pre_log()
log.post_log(ret, 'pass')
nt.assert_not_in(ret, log._Log__running,
@@ -85,15 +91,15 @@ def test_post_log_removes_complete():
@nt.raises(AssertionError)
-def check_post_log_incrment_summary_bad():
- log = Log(100)
+def test_post_log_incrment_summary_bad():
+ log = Log(100, False)
ret = log.pre_log()
log.post_log(ret, 'fails')
-def check_output(stat):
- """ Test that dry output returns the expected values """
- log = Log(100)
+def check_output_terse(stat):
+ """ Test that terse output returns the expected values """
+ log = Log(100, False)
for x in stat:
ret = log.pre_log()
@@ -101,7 +107,7 @@ def check_output(stat):
# Print to stdout, and then capture it, the capture absolutely needs to
# imediatly after log.log()
- log.log()
+ log.log('test', 'pass')
output = sys.stdout.getvalue().strip() # sys.stdout is a StringIO in nose
# Create a count of the statuses in alphabetical order. What we need to end
@@ -119,24 +125,53 @@ def check_output(stat):
msg="Did not return execpted output: " + expected)
+def check_output_verbose(stat):
+ """ Test that verbose output returns the expected values """
+ log = Log(100, True)
+
+ for x in stat:
+ ret = log.pre_log()
+ log.post_log(ret, x)
+
+ # Print to stdout, and then capture it, the capture absolutely needs to
+ # imediatly after log.log()
+ log.log('test', 'pass')
+ output = sys.stdout.getvalue().strip() # sys.stdout is a StringIO in nose
+
+ # Create a count of the statuses in alphabetical order. What we need to end
+ # up with is something like: 'crash': 2, 'skip': 1
+ s = []
+ for x in sorted(set(stat)):
+ s.append("{0}: {1}".format(x, stat.count(x)))
+
+ expected = ('pass :: test\n'
+ '[{0}/100] {1} Running Test(s):'.format(
+ str(len(stat)).zfill(3),
+ ", ".join(s)))
+
+ nt.assert_equal(output, expected,
+ msg="Did not return execpted output: " + expected)
+
+
def gen_test_output():
""" Generate a set of tests for checking __summary output
This generates severl hundered tests
"""
- yieldable = check_output
+ terse = check_output_terse
+ verbose = check_output_verbose
# test dry run seperately, we don't want to test it mixed in with other
# statuses, since it shouldn't be mixed
- yieldable.description = "Test output for status combinations: dry-run"
- yield yieldable, ['dry-run']
+ terse.description = "Test output for status combinations: dry-run"
+ yield terse, ['dry-run']
- yieldable.description = "Test output for status combinations: dry-run dry-run"
- yield yieldable, ['dry-run', 'dry-run']
+ terse.description = "Test output for status combinations: dry-run dry-run"
+ yield terse, ['dry-run', 'dry-run']
- yieldable.description = "Test output for status combinations: dry-run dry-run dry-run"
- yield yieldable, ['dry-run', 'dry-run', 'dry-run']
+ terse.description = "Test output for status combinations: dry-run dry-run dry-run"
+ yield terse, ['dry-run', 'dry-run', 'dry-run']
# All combinations except dry-run up to 3 in length. We could generate
# more, but it quickly becomes overwhelming, and the usefulness is
@@ -144,6 +179,10 @@ def gen_test_output():
for r in xrange(1, 4):
for stat in itertools.product(valid_statuses[:-1],
repeat=r):
- yieldable.description = "Test output for status: " + \
+ terse.description = "Test terse output for status: " + \
+ " ".join([str(x) for x in stat])
+ yield terse, stat
+
+ verbose.description = "Test verbose output for status: " + \
" ".join([str(x) for x in stat])
- yield yieldable, stat
+ yield verbose, stat
diff --git a/piglit-resume.py b/piglit-resume.py
index 7b82420..5d41b9a 100755
--- a/piglit-resume.py
+++ b/piglit-resume.py
@@ -31,6 +31,10 @@ import framework.core as core
def main():
parser = argparse.ArgumentParser()
+ parser.add_argument("-v", "--verbose",
+ action="store_true",
+ help="Produce a line of output for each test before "
+ "and after it runs")
parser.add_argument("results_path",
type=path.realpath,
metavar="<Results Path>",
@@ -44,6 +48,10 @@ def main():
execute=results.options['execute'],
valgrind=results.options['valgrind'],
dmesg=results.options['dmesg'])
+
+ # Verbosity isn't a useful environment setting, and the user should be able
+ # to set it on their own.
+ env.verbose = results.options['verbose']
# Change working directory to the piglit directory
os.chdir(path.dirname(path.realpath(sys.argv[0])))
diff --git a/piglit-run.py b/piglit-run.py
index ba5c925..5fc9baf 100755
--- a/piglit-run.py
+++ b/piglit-run.py
@@ -82,6 +82,10 @@ def main():
action="store_true",
help="Capture a difference in dmesg before and "
"after each test. Implies -1/--no-concurrency")
+ parser.add_argument("-v", "--verbose",
+ action="store_true",
+ help="Produce a line of output for each test before "
+ "and after it runs")
parser.add_argument("test_profile",
metavar="<Path to one or more test profile(s)>",
nargs='+',
@@ -115,7 +119,8 @@ def main():
include_filter=args.include_tests,
execute=args.execute,
valgrind=args.valgrind,
- dmesg=args.dmesg)
+ dmesg=args.dmesg,
+ verbose=args.verbose)
# Change working directory to the root of the piglit directory
piglit_dir = path.dirname(path.realpath(sys.argv[0]))
--
1.8.5.5
More information about the Piglit
mailing list