changeset 27396:64c584070fc7

run-tests: show scheduling with --showchannels

This gives one line of output per second with one column per -j level
that allows analyzing test scheduling problems. First 24 seconds of
output at -j 30 looks like this:

  0                                                                .
  1  = = = = = = = = = = = = = = = = = = = = = = = = = = = = = =   s.
  2  c c o c r l g r s s = c p = c h c a h c g c h c b c c l l c   ss
  3  h o b o e a e u u u c o a h o e o c g o l h g h u o = a o =   s
  4  e n s n b r n n b b   m t g n l n l w n o e w e n n e r g i   .
  5  c t o = a g d - r r = m c w v p v . e v g c e c d v x g . m
  6  k r l r s e o t e e b a h e e . e . b e . k b k l e t e . p
  7  - i e e e f c e p p u n b b r . r . - r . - - - e r e f . o   .
  8  p b t v - i . s o o n d o d t . t . c t . c s = 2 t n i . r
  9  y - e s c l . t - . d - m i - . - . o - . o y r - - s l . t
 10  3 p - e h e . s s . l t b r s . s . m s . d m e f s i e . .
 11  - e c t e s . . v . e e . . v . v . m v . e r n o v o s . .
 12  c r h . c - . . n . 2 m . . n . n . a n . . e a r n n . . .
 13  o f e . k u . . . . - p . . - . - . n - . . v m m - . . . .
 14  m . c . - p . . . . e l . . s . m . d s . . . e a e . . . .
 15  p . k . r d . . . . x a . . i . o . s o . . . - t n . . . .
 16  a . h . e a . . . . c t . . n . v . . u . . . m . c . . . .
 17  t . e . s t . . . . h e . . k . e . . r . . . e . o . . . .
 18  . . a . t e . . . . a . . . . . . . . c . . . r . d . . . .
 19  . . d . o . . . . . n . . . . . . . . e . . . g . i . . . .
 20  . . s . r . . . . . g . . . . . . . . . . . . e . n . . . .
 21  . . . . e . . . . . e . . . . . . . . . . . . 2 . g . . . .
 22  . . . . . . . . . . . . . . . . . . . . . . . . . . . . . .
 23  . . . . . . . . . . . . . . . . . . . . . . . . . . . . . .   .
 24  . . . . . . . . . . . . . . . . . . . . . . . . . = . . . .   ^C

Test names read off vertically, beginning with '='. Idle time (not
shown) appears as blank space.

--- a/tests/run-tests.py	Sun Dec 06 15:14:01 2015 -0600
+++ b/tests/run-tests.py	Mon Dec 07 16:16:06 2015 -0600
@@ -267,6 +267,8 @@
                       help='run statprof on run-tests')
     parser.add_option('--allow-slow-tests', action='store_true',
                       help='allow extremely slow tests')
+    parser.add_option('--showchannels', action='store_true',
+                      help='show scheduling channels')
 
     for option, (envvar, default) in defaults.items():
         defaults[option] = type(default)(os.environ.get(envvar, default))
@@ -347,6 +349,9 @@
     else:
         options.whitelisted = {}
 
+    if options.showchannels:
+        options.nodiff = True
+
     return (options, args)
 
 def rename(src, dst):
@@ -1418,7 +1423,7 @@
 
     def __init__(self, testdir, jobs=1, whitelist=None, blacklist=None,
                  retest=False, keywords=None, loop=False, runs_per_test=1,
-                 loadtest=None,
+                 loadtest=None, showchannels=False,
                  *args, **kwargs):
         """Create a new instance that can run tests with a configuration.
 
@@ -1455,6 +1460,7 @@
         self._loop = loop
         self._runs_per_test = runs_per_test
         self._loadtest = loadtest
+        self._showchannels = showchannels
 
     def run(self, result):
         # We have a number of filters that need to be applied. We do this
@@ -1501,7 +1507,14 @@
         done = queue.Queue()
         running = 0
 
+        channels = [""] * self._jobs
+
         def job(test, result):
+            for n, v in enumerate(channels):
+                if not v:
+                    channel = n
+                    break
+            channels[channel] = "=" + test.name[5:].split(".")[0]
             try:
                 test(result)
                 done.put(None)
@@ -1510,9 +1523,33 @@
             except: # re-raises
                 done.put(('!', test, 'run-test raised an error, see traceback'))
                 raise
+            channels[channel] = ''
+
+        def stat():
+            count = 0
+            while channels:
+                d = '\n%03s  ' % count
+                for n, v in enumerate(channels):
+                    if v:
+                        d += v[0]
+                        channels[n] = v[1:] or '.'
+                    else:
+                        d += ' '
+                    d += ' '
+                with iolock:
+                    sys.stdout.write(d + '  ')
+                    sys.stdout.flush()
+                for x in xrange(10):
+                    if channels:
+                        time.sleep(.1)
+                count += 1
 
         stoppedearly = False
 
+        if self._showchannels:
+            statthread = threading.Thread(target=stat, name="stat")
+            statthread.start()
+
         try:
             while tests or running:
                 if not done.empty() or running == self._jobs or not tests:
@@ -1553,6 +1590,8 @@
             for test in runtests:
                 test.abort()
 
+        channels = []
+
         return result
 
 class TextTestRunner(unittest.TextTestRunner):
@@ -1942,6 +1981,7 @@
                               keywords=kws,
                               loop=self.options.loop,
                               runs_per_test=self.options.runs_per_test,
+                              showchannels=self.options.showchannels,
                               tests=tests, loadtest=self._gettest)
             verbosity = 1
             if self.options.verbose: