[Piglit] [Patch v2 4/5] framework: refactor the log module
Dylan Baker
baker.dylan.c at gmail.com
Mon Jul 7 17:17:24 PDT 2014
On Monday, July 07, 2014 07:35:55 PM Ilia Mirkin wrote:
> On Sun, Jul 6, 2014 at 3:13 AM, Dylan Baker <baker.dylan.c at gmail.com> wrote:
> > This refactors the log module away from a single class that does
> > everything to having two classes. The first class LogFactory, is a state
> > manager that returns BaseLog derived objects when it's get() method is
> > called. However, it mainly acts as a shared state manager.
> >
> > The BaseLog derived classes provide three public methods; start(),
> > log(), summary().
> >
> > This makes the interfaces much cleaner, just 3 public methods that are
> > fairly obvious and clearly documented. It uses inheritance for more
> > shared code, and is just generally much less complex than the previous
> > implementation
> >
> > v2: - Fix summary line in the verbose logger to support using '\r'. This
> >
> > works by printing the summary at the end of start() and log()
> >
> > - add -v/--verbose option back (Ilia)
> >
> > Signed-off-by: Dylan Baker <baker.dylan.c at gmail.com>
> > ---
>
> [...]
>
> > +class QuietLog(BaseLog):
> > + """ A logger providing minimal status output
> >
> > - def _format_summary(self):
> > - """ return a summary of the statuses """
> > - return ", ".join("{0}: {1}".format(k, self.__summary[k])
> > - for k in sorted(self.__summary))
> > + This logger provides only a ninja like [x/y] pass: z, fail: w ...
> > output.
> >
> > - def _format_running(self):
> > - """ return running tests """
> > - return "Running Test(s): {}".format(
> > - " ".join([str(x).zfill(self.__pad) for x in self.__running]))
> > + It uses \r to print over the same line when printing to a tty. If
> > + sys.stdout is not a tty then it prints \n at the end of the line
> > instead
> >
> > - def _format_percent(self):
> > - """ return the percentage of tess completed """
> > - return "{0}/{1}".format(str(self.__complete).zfill(self.__pad),
> > - str(self.__total).zfill(self.__pad))
> > + Arguments:
> > + status -- the status to print
> >
> > - def __print(self, name, result):
> > - """ Do the actual printing """
> > - self._write_output(self.__output.format(
> > - percent=self._format_percent(),
> > - running=self._format_running(),
> > - summary=self._format_summary(),
> > - name=name,
> > - result=result))
> > + """
> > + _test_counter = itertools.count()
> > +
> > + def __init__(self, *args, **kwargs):
> > + super(QuietLog, self).__init__(*args, **kwargs)
> >
> > - @synchronized_self
> > - def log(self, name, result, value):
> > - """ Print to the screen
> > + # If the output is a tty we can use '\r' (return, no linebreak)
> > to
> > + # print over the existing line, if stdout isn't a tty that will
> > not + # work (and can break systems like jenkins), so we print a
> > \n instead + if sys.stdout.isatty():
> > + self._endcode = '\r'
> > + else:
> > + self._endcode = '\n'
> >
> > - Works by moving the cursor back to the front of the line and
> > printing - over it.
> > + self.__counter = self._test_counter.next()
> > + self._state['running'].append(self.__counter)
> > +
> > + def start(self, name):
> > + pass
> > +
> > + def log(self, status):
> > + # increment complete
> > + self._state['complete'] += 1
> > +
> > + # Add to the summary dict
> > + assert status in self.SUMMARY_KEYS
> > + self._state['summary'][status] += 1
> > +
> > + self._print_summary()
> > + self._state['running'].remove(self.__counter)
> > +
> > + def summary(self):
> > + self._print_summary()
> >
> > - Arguments:
> > - name -- the name of the test
> > - result -- the result of the test
> > - value -- the number of the test to remove
> > + def _print_summary(self):
> > + """ Print the summary result
> > +
> > + this prints '[done/total] {status}', it is a private method
> > hidden from + the children of this class (VerboseLog)
> >
> > """
> >
> > - assert result in self.__summary_keys
> > - self.__print(name, result)
> > + out = '[{done}/{total}] {status} Running Test(s):
> > {running}'.format( +
> > done=str(self._state['complete']).zfill(self._pad),
> > + total=str(self._state['total']).zfill(self._pad),
> > + status=', '.join('{0}: {1}'.format(k, v) for k, v in
> > + sorted(self._state['summary'].iteritems())),
> > + running=" ".join(str(x) for x in self._state['running'])
> > + )
> > +
> > + self._print(out)
> > +
> > + def _print(self, out):
> > + """ Shared print method that ensures any bad lines are
> > overwritten """ + with self._LOCK:
> > + # If the new line is shorter than the old one add trailing
> > + # whitespace
> > + pad = self._state['lastlength'] - len(out)
> > +
> > + sys.stdout.write(out)
> > + if pad > 0:
> > + sys.stdout.write(' ' * pad)
> > + sys.stdout.write(self._endcode)
> > + sys.stdout.flush()
> >
> > - # Mark running complete
> > - assert value in self.__running
> > - self.__running.remove(value)
> > + # Set the length of the line just printed (minus the spaces since
> > we + # don't care if we leave whitespace) so that the next line
> > will print + # extra whitespace if necissary
> > + self._state['lastlength'] = len(out)
>
> This should be done under the lock, no? And also the += 1's...
>
> > - # increment the number of completed tests
> > - self.__complete += 1
> >
> > - assert result in self.__summary_keys
> > - self.__summary[result] += 1
>
> [...]
>
> > +class LogManager(object):
> > + """ Creates new log objects
> > +
> > + Each of the log objects it creates have two accessible methods:
> > start() and + log(); neither method should return anything, and they
> > must be thread safe. + log() should accept a single argument, which is
> > the status the test + returned. start() should also take a single
> > argument, the name of the test +
> > + When the LogManager is initialized it is initialized with an argument
> > which + determines which Log class it will return (they are set via
> > the LOG_MAP + dictionary, which maps string names to class callables),
> > it will return + these as long as it exists.
> > +
> > + Arguments:
> > + logger -- a string name of a logger to use
> > + total -- the total number of test to run
> > +
> > + """
> > + LOG_MAP = {
> > + 'quiet': QuietLog,
> > + 'verbose': VerboseLog,
> > + }
> > +
> > + def __init__(self, logger, total):
> > + assert logger in self.LOG_MAP
> > + self._log = self.LOG_MAP[logger]
> > + self._state = {
> > + 'total': total,
> > + 'summary': collections.defaultdict(lambda: 0),
> > + 'lastlength': 0,
> > + 'complete': 0,
> > + 'running': [],
> > + } # XXX Does access to this dict need locking?
>
> Can two threads call print at the same time? I think they can, so the
> answer is "yes", since while no 2 threads run at the same time due to
> the GIL, they may get interrupted at arbitrary points. What was wrong
> with the @synchronized_self stuff -- just stick that on the log()
> method...
I don't think that synchronized_self would actually work for the BaseLog
derived methods. Unless I'm completely misunderstanding synchronized_self uses
the repr() of self as a key for a dictionary, and the lock used is the value
of that key. Which means that the value's are effectively instance variables,
which works out well if you're passing a single instance to multiple threads,
but this doesn't do that. It passes a unique instance to each thread each time
a test is started.
Or did I completely misunderstand how synchronized_self works?
>
> With that fixed (which is also my comment above), patches 1-4
> Reviewed-by: Ilia Mirkin <imirkin at alum.mit.edu>
>
> (nothing wrong with patch 5, just haven't looked at it yet)
>
> -ilia
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 473 bytes
Desc: This is a digitally signed message part.
URL: <http://lists.freedesktop.org/archives/piglit/attachments/20140707/e100b1bd/attachment.sig>
More information about the Piglit
mailing list