[Piglit] [PATCH] framework: add a verbose flag to produce a result spew

Dylan Baker baker.dylan.c at gmail.com
Sat Feb 15 04:01:11 PST 2014


On Saturday, February 15, 2014 04:52:30 AM Ilia Mirkin wrote:
> On Sat, Feb 15, 2014 at 4:49 AM, Dylan Baker <baker.dylan.c at gmail.com> 
wrote:
> > On Saturday, February 15, 2014 04:15:13 AM Ilia Mirkin wrote:
> >> This restores a similar output to the old one for use-cases where a spew
> >> is useful, such as when hangs can happen and the on-screen output is the
> >> only record.
> >> 
> >> Signed-off-by: Ilia Mirkin <imirkin at alum.mit.edu>
> >> ---
> >> 
> >> Sorry, this is a little dirty. Can't think of a great way around it,
> >> given
> >> the current log api. Perhaps it should become log_start/log_end?
> >> 
> >> Also, why does log() happen before the test runs/mark_complete? Is that
> >> just to deal with having an output before the very first test completes?
> >> 
> >> Note, this probably depends on some of the earlier patches I sent to the
> >> list.
> >> 
> >>  framework/core.py | 10 +++++++---
> >>  framework/log.py  | 17 ++++++++++++-----
> >>  piglit-resume.py  |  3 ++-
> >>  piglit-run.py     |  7 ++++++-
> >>  4 files changed, 27 insertions(+), 10 deletions(-)
> >> 
> >> diff --git a/framework/core.py b/framework/core.py
> >> index 7b2083b..d85bf70 100644
> >> --- a/framework/core.py
> >> +++ b/framework/core.py
> >> 
> >> @@ -356,7 +356,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 = []
> >> 
> >> @@ -364,6 +364,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, @@ -440,7 +441,7 @@ class Test(object):
> >>          # Run the test
> >>          
> >>          if env.execute:
> >>              try:
> >> -                log.log()
> >> +                log.log(env.verbose, log_current, path, "running")
> >> 
> >>                  time_start = time.time()
> >>                  dmesg.update_dmesg()
> >>                  self._test_hook_execute_run()
> >> 
> >> @@ -464,6 +465,9 @@ class Test(object):
> >>                  result['traceback'] = \
> >>                  
> >>                      "".join(traceback.format_tb(sys.exc_info()[2]))
> >> 
> >> +            if env.verbose:
> >> +                log.log(env.verbose, log_current, path,
> >> result["result"])
> >> +
> >> 
> >>              if 'subtest' in result and len(result['subtest']) > 1:
> >>                  for test in result['subtest']:
> >>                      res = result['result'] = result['subtest'][test]
> >> 
> >> @@ -473,7 +477,7 @@ class Test(object):
> >>                  counts[result['result']] = 1
> >>                  json_writer.write_dict_item(path, result)
> >>          
> >>          else:
> >> -            log.log()
> >> +            log.log(env.verbose, log_current, path, "noexec")
> >> 
> >>          log.mark_complete(log_current, counts)
> >> 
> >> diff --git a/framework/log.py b/framework/log.py
> >> index 8ae7541..90998ba 100644
> >> --- a/framework/log.py
> >> +++ b/framework/log.py
> >> 
> >> @@ -73,17 +73,24 @@ class Log(object):
> >>              self.__summary[k] = self.__summary.get(k, 0) + v
> >>      
> >>      @synchronized_self
> >> 
> >> -    def log(self):
> >> 
> >> +    def log(self, verbose, id, 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} \r".format(self._percent(),
> >> self._running())) -        # Need to flush explicitly, otherwise it all
> >> gets buffered without a -        # newline.
> >> -        sys.stdout.flush()
> >> +        if verbose:
> >> +            sys.stdout.write("[{0}/{1}] :: {2:>7} :: {3}\n".format(
> >> +                str(id).zfill(self.__pad),
> >> +                str(self.__total).zfill(self.__pad),
> >> +                result,
> >> +                name))
> >> +        else:
> >> +            sys.stdout.write("{0} {1} \r".format(self._percent(),
> >> self._running())) +            # Need to flush explicitly, otherwise it
> >> all
> >> gets buffered without a +            # newline.
> >> +            sys.stdout.flush()
> >> 
> >>      @synchronized_self
> >> 
> >>      def get_current(self):
> >> diff --git a/piglit-resume.py b/piglit-resume.py
> >> index 7b82420..06bba4d 100755
> >> --- a/piglit-resume.py
> >> +++ b/piglit-resume.py
> >> 
> >> @@ -43,7 +43,8 @@ def main():
> >>                             include_filter=results.options['filter'],
> >>                             execute=results.options['execute'],
> >>                             valgrind=results.options['valgrind'],
> >> 
> >> -                           dmesg=results.options['dmesg'])
> >> +                           dmesg=results.options['dmesg'],
> >> +                           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]))
> > 
> > I'd rather not have this kind of if branching, it's going to eat a lot of
> > the performance gain of the terse output, and and that point why bother?
> > I've sent out a patch that kinda cuts the middle between what I wrote and
> > what was there before.
> 
> Yeah, I saw that... not sure what you mean by cutting the performance
> gains. Are you suggesting that an appreciable amount of CPU time is
> spent in computing "if verbose"? Perhaps I'm not understanding
> something.
> 
> I actually really like the new "compressed" output. It's a lot easier
> to see what's going on with the summary than with the spew. And I'm
> betting that Eric will too, since his use-case is "I messed up calling
> piglit and everything's failing". This is to handle Dave's use-case of
> "the VM died before flush() and all I have is what was on the
> console".
> 
>   -ilia

So, here's a crazy idea, what if we did something like this:

def __init__(self, total, verbosity):
		self.__total = total                                                                                                                                                                
		self.__complete = 1                                                                                                                                                                  
		self.__pad = len(str(self.__total))     

		if verbose == 'low':
			self.__output_string = '[{current}/{total}] {status}'
		elif verbose == 'high':
			self.__output_string = something else...
		else:
			raise Exception("verbosity not set correctly!")

def log(self, arguments):
	assert isinstance(arguments, dict)
	sys.stdout.write(self.__output_string.format(arguments))
	sys.stdout.flush()

We move all of the if's into the constructor, which alleviates my concern of 
calling if/else on each use of .log(), while allowing differen logging output. 
It would reduce code, it would make it easy for other to implement their own 
logging output, and we would only need to pass the verbosity level to one 
call, once.

I also think it might be worth changing the API, if we had methods like 
pre_log() and post_log() (and dropped mark_complete and get_current) we could 
make pre_log a no-op for terse loggers, and could have it do something for 
more wordy ones.

-Dylan
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 490 bytes
Desc: This is a digitally signed message part.
URL: <http://lists.freedesktop.org/archives/piglit/attachments/20140215/2cbd77f6/attachment-0001.pgp>


More information about the Piglit mailing list