4 # This file and its contents are supplied under the terms of the
5 # Common Development and Distribution License ("CDDL"), version 1.0.
6 # You may only use this file in accordance with the terms of version
9 # A full copy of the text of the CDDL should have accompanied this
10 # source. A copy of the CDDL is also available via the Internet at
11 # http://www.illumos.org/license/CDDL.
15 # Copyright (c) 2012, 2016 by Delphix. All rights reserved.
16 # Copyright (c) 2017, Chris Fraire <cfraire@me.com>.
22 from logging.handlers import WatchedFileHandler
23 from datetime import datetime
24 from optparse import OptionParser
25 from pwd import getpwnam
26 from pwd import getpwuid
27 from select import select
28 from subprocess import PIPE
29 from subprocess import Popen
31 from sys import maxint
32 from threading import Timer
35 BASEDIR = '/var/tmp/test_results'
36 KILL = '/usr/bin/kill'
37 TRUE = '/usr/bin/true'
38 SUDO = '/usr/bin/sudo'
40 # Custom class to reopen the log file in case it is forcibly closed by a test.
41 class WatchedFileHandlerClosed(WatchedFileHandler):
42 """Watch files, including closed files.
43 Similar to (and inherits from) logging.handler.WatchedFileHandler,
44 except that IOErrors are handled by reopening the stream and retrying.
45 This will be retried up to a configurable number of times before
49 def __init__(self, filename, mode='a', encoding=None, delay=0, max_tries=5):
50 self.max_tries = max_tries
52 WatchedFileHandler.__init__(self, filename, mode, encoding, delay)
54 def emit(self, record):
57 WatchedFileHandler.emit(self, record)
60 except IOError as err:
61 if self.tries == self.max_tries:
64 self.stream = self._open()
69 runresults = {'PASS': 0, 'FAIL': 0, 'SKIP': 0, 'KILLED': 0}
73 self.returncode = None
79 def done(self, proc, killed):
81 Finalize the results of this Cmd.
84 m, s = divmod(time() - self.starttime, 60)
85 self.runtime = '%02d:%02d' % (m, s)
86 self.returncode = proc.returncode
88 self.result = 'KILLED'
89 Result.runresults['KILLED'] += 1
90 elif self.returncode is 0:
92 Result.runresults['PASS'] += 1
93 elif self.returncode is not 0:
95 Result.runresults['FAIL'] += 1
100 This class is a slightly modified version of the 'Stream' class found
101 here: http://goo.gl/aSGfv
103 def __init__(self, stream):
109 return self.stream.fileno()
111 def read(self, drain=0):
113 Read from the file descriptor. If 'drain' set, read until EOF.
115 while self._read() is not None:
121 Read up to 4k of data from this output stream. Collect the output
122 up to the last newline, and append it to any leftover data from a
123 previous call. The lines are stored as a (timestamp, data) tuple
124 for easy sorting/merging later.
127 buf = os.read(fd, 4096)
134 buf = self._buf + buf
135 tmp, rest = buf.rsplit('\n', 1)
138 rows = tmp.split('\n')
139 self.lines += [(now, r) for r in rows]
145 def __init__(self, pathname, outputdir=None, timeout=None, user=None):
146 self.pathname = pathname
147 self.outputdir = outputdir or 'BASEDIR'
148 self.timeout = timeout
149 self.user = user or ''
151 self.result = Result()
153 if self.timeout is None:
157 return "Pathname: %s\nOutputdir: %s\nTimeout: %s\nUser: %s\n" % \
158 (self.pathname, self.outputdir, self.timeout, self.user)
160 def kill_cmd(self, proc):
162 Kill a running command due to timeout, or ^C from the keyboard. If
163 sudo is required, this user was verified previously.
166 do_sudo = len(self.user) != 0
169 cmd = [SUDO, KILL, signal, str(proc.pid)]
179 def update_cmd_privs(self, cmd, user):
181 If a user has been specified to run this Cmd and we're not already
182 running as that user, prepend the appropriate sudo command to run
185 me = getpwuid(os.getuid())
187 if not user or user is me:
190 ret = '%s -E -u %s %s' % (SUDO, user, cmd)
191 return ret.split(' ')
193 def collect_output(self, proc):
195 Read from stdout/stderr as data becomes available, until the
196 process is no longer running. Return the lines from the stdout and
197 stderr Output objects.
199 out = Output(proc.stdout)
200 err = Output(proc.stderr)
202 while proc.returncode is None:
204 res = select([out, err], [], [], .1)
210 return out.lines, err.lines
212 def run(self, options):
214 This is the main function that runs each individual test.
215 Determine whether or not the command requires sudo, and modify it
216 if needed. Run the command, and update the result object.
218 if options.dryrun is True:
222 privcmd = self.update_cmd_privs(self.pathname, self.user)
225 if not os.path.isdir(self.outputdir):
226 os.makedirs(self.outputdir, mode=0777)
232 self.result.starttime = time()
233 proc = Popen(privcmd, stdout=PIPE, stderr=PIPE)
235 # Allow a special timeout value of 0 to mean infinity
236 if int(self.timeout) == 0:
237 self.timeout = maxint
238 t = Timer(int(self.timeout), self.kill_cmd, [proc])
240 self.result.stdout, self.result.stderr = self.collect_output(proc)
241 except KeyboardInterrupt:
243 fail('\nRun terminated at user request.')
247 self.result.done(proc, self.killed)
251 Initialize enough of the test result that we can log a skipped
255 Result.runresults['SKIP'] += 1
256 self.result.stdout = self.result.stderr = []
257 self.result.starttime = time()
258 m, s = divmod(time() - self.result.starttime, 60)
259 self.result.runtime = '%02d:%02d' % (m, s)
260 self.result.result = 'SKIP'
262 def log(self, logger, options):
264 This function is responsible for writing all output. This includes
265 the console output, the logfile of all results (with timestamped
266 merged stdout and stderr), and for each test, the unmodified
267 stdout/stderr/merged in it's own file.
272 logname = getpwuid(os.getuid()).pw_name
273 user = ' (run as %s)' % (self.user if len(self.user) else logname)
274 msga = 'Test: %s%s ' % (self.pathname, user)
275 msgb = '[%s] [%s]' % (self.result.runtime, self.result.result)
276 pad = ' ' * (80 - (len(msga) + len(msgb)))
278 # If -q is specified, only print a line for tests that didn't pass.
279 # This means passing tests need to be logged as DEBUG, or the one
280 # line summary will only be printed in the logfile for failures.
281 if not options.quiet:
282 logger.info('%s%s%s' % (msga, pad, msgb))
283 elif self.result.result is not 'PASS':
284 logger.info('%s%s%s' % (msga, pad, msgb))
286 logger.debug('%s%s%s' % (msga, pad, msgb))
288 lines = sorted(self.result.stdout + self.result.stderr,
289 cmp=lambda x, y: cmp(x[0], y[0]))
291 for dt, line in lines:
292 logger.debug('%s %s' % (dt.strftime("%H:%M:%S.%f ")[:11], line))
294 if len(self.result.stdout):
295 with open(os.path.join(self.outputdir, 'stdout'), 'w') as out:
296 for _, line in self.result.stdout:
297 os.write(out.fileno(), '%s\n' % line)
298 if len(self.result.stderr):
299 with open(os.path.join(self.outputdir, 'stderr'), 'w') as err:
300 for _, line in self.result.stderr:
301 os.write(err.fileno(), '%s\n' % line)
302 if len(self.result.stdout) and len(self.result.stderr):
303 with open(os.path.join(self.outputdir, 'merged'), 'w') as merged:
304 for _, line in lines:
305 os.write(merged.fileno(), '%s\n' % line)
309 props = ['outputdir', 'timeout', 'user', 'pre', 'pre_user', 'post',
312 def __init__(self, pathname, outputdir=None, timeout=None, user=None,
313 pre=None, pre_user=None, post=None, post_user=None):
314 super(Test, self).__init__(pathname, outputdir, timeout, user)
316 self.pre_user = pre_user or ''
317 self.post = post or ''
318 self.post_user = post_user or ''
321 post_user = pre_user = ''
322 if len(self.pre_user):
323 pre_user = ' (as %s)' % (self.pre_user)
324 if len(self.post_user):
325 post_user = ' (as %s)' % (self.post_user)
326 return "Pathname: %s\nOutputdir: %s\nTimeout: %d\nPre: %s%s\nPost: " \
327 "%s%s\nUser: %s\n" % \
328 (self.pathname, self.outputdir, self.timeout, self.pre,
329 pre_user, self.post, post_user, self.user)
331 def verify(self, logger):
333 Check the pre/post scripts, user and Test. Omit the Test from this
334 run if there are any problems.
336 files = [self.pre, self.pathname, self.post]
337 users = [self.pre_user, self.user, self.post_user]
339 for f in [f for f in files if len(f)]:
340 if not verify_file(f):
341 logger.info("Warning: Test '%s' not added to this run because"
342 " it failed verification." % f)
345 for user in [user for user in users if len(user)]:
346 if not verify_user(user, logger):
347 logger.info("Not adding Test '%s' to this run." %
353 def run(self, logger, options):
355 Create Cmd instances for the pre/post scripts. If the pre script
356 doesn't pass, skip this Test. Run the post script regardless.
358 odir = os.path.join(self.outputdir, os.path.basename(self.pre))
359 pretest = Cmd(self.pre, outputdir=odir, timeout=self.timeout,
361 test = Cmd(self.pathname, outputdir=self.outputdir,
362 timeout=self.timeout, user=self.user)
363 odir = os.path.join(self.outputdir, os.path.basename(self.post))
364 posttest = Cmd(self.post, outputdir=odir, timeout=self.timeout,
368 if len(pretest.pathname):
370 cont = pretest.result.result is 'PASS'
371 pretest.log(logger, options)
378 test.log(logger, options)
380 if len(posttest.pathname):
381 posttest.run(options)
382 posttest.log(logger, options)
385 class TestGroup(Test):
386 props = Test.props + ['tests']
388 def __init__(self, pathname, outputdir=None, timeout=None, user=None,
389 pre=None, pre_user=None, post=None, post_user=None,
391 super(TestGroup, self).__init__(pathname, outputdir, timeout, user,
392 pre, pre_user, post, post_user)
393 self.tests = tests or []
396 post_user = pre_user = ''
397 if len(self.pre_user):
398 pre_user = ' (as %s)' % (self.pre_user)
399 if len(self.post_user):
400 post_user = ' (as %s)' % (self.post_user)
401 return "Pathname: %s\nOutputdir: %s\nTests: %s\nTimeout: %d\n" \
402 "Pre: %s%s\nPost: %s%s\nUser: %s\n" % \
403 (self.pathname, self.outputdir, self.tests, self.timeout,
404 self.pre, pre_user, self.post, post_user, self.user)
406 def verify(self, logger):
408 Check the pre/post scripts, user and tests in this TestGroup. Omit
409 the TestGroup entirely, or simply delete the relevant tests in the
410 group, if that's all that's required.
412 # If the pre or post scripts are relative pathnames, convert to
413 # absolute, so they stand a chance of passing verification.
414 if len(self.pre) and not os.path.isabs(self.pre):
415 self.pre = os.path.join(self.pathname, self.pre)
416 if len(self.post) and not os.path.isabs(self.post):
417 self.post = os.path.join(self.pathname, self.post)
419 auxfiles = [self.pre, self.post]
420 users = [self.pre_user, self.user, self.post_user]
422 for f in [f for f in auxfiles if len(f)]:
423 if self.pathname != os.path.dirname(f):
424 logger.info("Warning: TestGroup '%s' not added to this run. "
425 "Auxiliary script '%s' exists in a different "
426 "directory." % (self.pathname, f))
429 if not verify_file(f):
430 logger.info("Warning: TestGroup '%s' not added to this run. "
431 "Auxiliary script '%s' failed verification." %
435 for user in [user for user in users if len(user)]:
436 if not verify_user(user, logger):
437 logger.info("Not adding TestGroup '%s' to this run." %
441 # If one of the tests is invalid, delete it, log it, and drive on.
442 self.tests[:] = [f for f in self.tests if
443 verify_file(os.path.join(self.pathname, f))]
445 return len(self.tests) is not 0
447 def run(self, logger, options):
449 Create Cmd instances for the pre/post scripts. If the pre script
450 doesn't pass, skip all the tests in this TestGroup. Run the post
453 odir = os.path.join(self.outputdir, os.path.basename(self.pre))
454 pretest = Cmd(self.pre, outputdir=odir, timeout=self.timeout,
456 odir = os.path.join(self.outputdir, os.path.basename(self.post))
457 posttest = Cmd(self.post, outputdir=odir, timeout=self.timeout,
461 if len(pretest.pathname):
463 cont = pretest.result.result is 'PASS'
464 pretest.log(logger, options)
466 for fname in self.tests:
467 test = Cmd(os.path.join(self.pathname, fname),
468 outputdir=os.path.join(self.outputdir, fname),
469 timeout=self.timeout, user=self.user)
475 test.log(logger, options)
477 if len(posttest.pathname):
478 posttest.run(options)
479 posttest.log(logger, options)
482 class TestRun(object):
483 props = ['quiet', 'outputdir']
485 def __init__(self, options):
488 self.starttime = time()
489 self.timestamp = datetime.now().strftime('%Y%m%dT%H%M%S')
490 self.outputdir = os.path.join(options.outputdir, self.timestamp)
491 self.logger = self.setup_logging(options)
493 ('outputdir', BASEDIR),
504 s = 'TestRun:\n outputdir: %s\n' % self.outputdir
506 for key in sorted(self.tests.keys()):
507 s += '%s%s' % (self.tests[key].__str__(), '\n')
509 for key in sorted(self.testgroups.keys()):
510 s += '%s%s' % (self.testgroups[key].__str__(), '\n')
513 def addtest(self, pathname, options):
515 Create a new Test, and apply any properties that were passed in
516 from the command line. If it passes verification, add it to the
519 test = Test(pathname)
520 for prop in Test.props:
521 setattr(test, prop, getattr(options, prop))
523 if test.verify(self.logger):
524 self.tests[pathname] = test
526 def addtestgroup(self, dirname, filenames, options):
528 Create a new TestGroup, and apply any properties that were passed
529 in from the command line. If it passes verification, add it to the
532 if dirname not in self.testgroups:
533 testgroup = TestGroup(dirname)
534 for prop in Test.props:
535 setattr(testgroup, prop, getattr(options, prop))
537 # Prevent pre/post scripts from running as regular tests
538 for f in [testgroup.pre, testgroup.post]:
540 del filenames[filenames.index(f)]
542 self.testgroups[dirname] = testgroup
543 self.testgroups[dirname].tests = sorted(filenames)
545 testgroup.verify(self.logger)
547 def read(self, logger, options):
549 Read in the specified runfile, and apply the TestRun properties
550 listed in the 'DEFAULT' section to our TestRun. Then read each
551 section, and apply the appropriate properties to the Test or
552 TestGroup. Properties from individual sections override those set
553 in the 'DEFAULT' section. If the Test or TestGroup passes
554 verification, add it to the TestRun.
556 config = ConfigParser.RawConfigParser()
557 if not len(config.read(options.runfile)):
558 fail("Coulnd't read config file %s" % options.runfile)
560 for opt in TestRun.props:
561 if config.has_option('DEFAULT', opt):
562 setattr(self, opt, config.get('DEFAULT', opt))
563 self.outputdir = os.path.join(self.outputdir, self.timestamp)
565 for section in config.sections():
566 if 'tests' in config.options(section):
567 testgroup = TestGroup(section)
568 for prop in TestGroup.props:
569 for sect in ['DEFAULT', section]:
570 if config.has_option(sect, prop):
571 setattr(testgroup, prop, config.get(sect, prop))
573 # Repopulate tests using eval to convert the string to a list
574 testgroup.tests = eval(config.get(section, 'tests'))
576 if testgroup.verify(logger):
577 self.testgroups[section] = testgroup
579 elif 'autotests' in config.options(section):
580 testgroup = TestGroup(section)
581 for prop in TestGroup.props:
582 for sect in ['DEFAULT', section]:
583 if config.has_option(sect, prop):
584 setattr(testgroup, prop, config.get(sect, prop))
586 filenames = os.listdir(section)
587 # only files starting with "tst." are considered tests
588 filenames = [f for f in filenames if f.startswith("tst.")]
589 testgroup.tests = sorted(filenames)
591 if testgroup.verify(logger):
592 self.testgroups[section] = testgroup
596 for prop in Test.props:
597 for sect in ['DEFAULT', section]:
598 if config.has_option(sect, prop):
599 setattr(test, prop, config.get(sect, prop))
601 if test.verify(logger):
602 self.tests[section] = test
604 def write(self, options):
606 Create a configuration file for editing and later use. The
607 'DEFAULT' section of the config file is created from the
608 properties that were specified on the command line. Tests are
609 simply added as sections that inherit everything from the
610 'DEFAULT' section. TestGroups are the same, except they get an
611 option including all the tests to run in that directory.
614 defaults = dict([(prop, getattr(options, prop)) for prop, _ in
616 config = ConfigParser.RawConfigParser(defaults)
618 for test in sorted(self.tests.keys()):
619 config.add_section(test)
621 for testgroup in sorted(self.testgroups.keys()):
622 config.add_section(testgroup)
623 config.set(testgroup, 'tests', self.testgroups[testgroup].tests)
626 with open(options.template, 'w') as f:
627 return config.write(f)
629 fail('Could not open \'%s\' for writing.' % options.template)
631 def complete_outputdirs(self):
633 Collect all the pathnames for Tests, and TestGroups. Work
634 backwards one pathname component at a time, to create a unique
635 directory name in which to deposit test output. Tests will be able
636 to write output files directly in the newly modified outputdir.
637 TestGroups will be able to create one subdirectory per test in the
638 outputdir, and are guaranteed uniqueness because a group can only
639 contain files in one directory. Pre and post tests will create a
640 directory rooted at the outputdir of the Test or TestGroup in
641 question for their output.
645 tmp_dict = dict(self.tests.items() + self.testgroups.items())
646 total = len(tmp_dict)
647 base = self.outputdir
652 for testfile in tmp_dict.keys():
653 uniq = '/'.join(testfile.split('/')[components:]).lstrip('/')
656 tmp_dict[testfile].outputdir = os.path.join(base, uniq)
659 done = total == len(l)
661 def setup_logging(self, options):
663 Two loggers are set up here. The first is for the logfile which
664 will contain one line summarizing the test, including the test
665 name, result, and running time. This logger will also capture the
666 timestamped combined stdout and stderr of each run. The second
667 logger is optional console output, which will contain only the one
668 line summary. The loggers are initialized at two different levels
669 to facilitate segregating the output.
671 if options.dryrun is True:
674 testlogger = logging.getLogger(__name__)
675 testlogger.setLevel(logging.DEBUG)
677 if options.cmd is not 'wrconfig':
680 os.makedirs(self.outputdir, mode=0777)
684 filename = os.path.join(self.outputdir, 'log')
686 logfile = WatchedFileHandlerClosed(filename)
687 logfile.setLevel(logging.DEBUG)
688 logfilefmt = logging.Formatter('%(message)s')
689 logfile.setFormatter(logfilefmt)
690 testlogger.addHandler(logfile)
692 cons = logging.StreamHandler()
693 cons.setLevel(logging.INFO)
694 consfmt = logging.Formatter('%(message)s')
695 cons.setFormatter(consfmt)
696 testlogger.addHandler(cons)
700 def run(self, options):
702 Walk through all the Tests and TestGroups, calling run().
704 if not options.dryrun:
706 os.chdir(self.outputdir)
708 fail('Could not change to directory %s' % self.outputdir)
709 for test in sorted(self.tests.keys()):
710 self.tests[test].run(self.logger, options)
711 for testgroup in sorted(self.testgroups.keys()):
712 self.testgroups[testgroup].run(self.logger, options)
715 if Result.total is 0:
718 print '\nResults Summary'
719 for key in Result.runresults.keys():
720 if Result.runresults[key] is not 0:
721 print '%s\t% 4d' % (key, Result.runresults[key])
723 m, s = divmod(time() - self.starttime, 60)
725 print '\nRunning Time:\t%02d:%02d:%02d' % (h, m, s)
726 print 'Percent passed:\t%.1f%%' % ((float(Result.runresults['PASS']) /
727 float(Result.total)) * 100)
728 print 'Log directory:\t%s' % self.outputdir
731 def verify_file(pathname):
733 Verify that the supplied pathname is an executable regular file.
735 if os.path.isdir(pathname) or os.path.islink(pathname):
738 if os.path.isfile(pathname) and os.access(pathname, os.X_OK):
744 def verify_user(user, logger):
746 Verify that the specified user exists on this system, and can execute
747 sudo without being prompted for a password.
749 testcmd = [SUDO, '-n', '-u', user, TRUE]
751 if user in Cmd.verified_users:
757 logger.info("Warning: user '%s' does not exist.", user)
762 if p.returncode is not 0:
763 logger.info("Warning: user '%s' cannot use passwordless sudo.", user)
766 Cmd.verified_users.append(user)
771 def find_tests(testrun, options):
773 For the given list of pathnames, add files as Tests. For directories,
774 if do_groups is True, add the directory as a TestGroup. If False,
775 recursively search for executable files.
778 for p in sorted(options.pathnames):
780 for dirname, _, filenames in os.walk(p):
781 if options.do_groups:
782 testrun.addtestgroup(dirname, filenames, options)
784 for f in sorted(filenames):
785 testrun.addtest(os.path.join(dirname, f), options)
787 testrun.addtest(p, options)
790 def fail(retstr, ret=1):
791 print '%s: %s' % (argv[0], retstr)
795 def options_cb(option, opt_str, value, parser):
796 path_options = ['runfile', 'outputdir', 'template']
798 if option.dest is 'runfile' and '-w' in parser.rargs or \
799 option.dest is 'template' and '-c' in parser.rargs:
800 fail('-c and -w are mutually exclusive.')
802 if opt_str in parser.rargs:
803 fail('%s may only be specified once.' % opt_str)
805 if option.dest is 'runfile':
806 parser.values.cmd = 'rdconfig'
807 if option.dest is 'template':
808 parser.values.cmd = 'wrconfig'
810 setattr(parser.values, option.dest, value)
811 if option.dest in path_options:
812 setattr(parser.values, option.dest, os.path.abspath(value))
816 parser = OptionParser()
817 parser.add_option('-c', action='callback', callback=options_cb,
818 type='string', dest='runfile', metavar='runfile',
819 help='Specify tests to run via config file.')
820 parser.add_option('-d', action='store_true', default=False, dest='dryrun',
821 help='Dry run. Print tests, but take no other action.')
822 parser.add_option('-g', action='store_true', default=False,
823 dest='do_groups', help='Make directories TestGroups.')
824 parser.add_option('-o', action='callback', callback=options_cb,
825 default=BASEDIR, dest='outputdir', type='string',
826 metavar='outputdir', help='Specify an output directory.')
827 parser.add_option('-p', action='callback', callback=options_cb,
828 default='', dest='pre', metavar='script',
829 type='string', help='Specify a pre script.')
830 parser.add_option('-P', action='callback', callback=options_cb,
831 default='', dest='post', metavar='script',
832 type='string', help='Specify a post script.')
833 parser.add_option('-q', action='store_true', default=False, dest='quiet',
834 help='Silence on the console during a test run.')
835 parser.add_option('-t', action='callback', callback=options_cb, default=60,
836 dest='timeout', metavar='seconds', type='int',
837 help='Timeout (in seconds) for an individual test.')
838 parser.add_option('-u', action='callback', callback=options_cb,
839 default='', dest='user', metavar='user', type='string',
840 help='Specify a different user name to run as.')
841 parser.add_option('-w', action='callback', callback=options_cb,
842 default=None, dest='template', metavar='template',
843 type='string', help='Create a new config file.')
844 parser.add_option('-x', action='callback', callback=options_cb, default='',
845 dest='pre_user', metavar='pre_user', type='string',
846 help='Specify a user to execute the pre script.')
847 parser.add_option('-X', action='callback', callback=options_cb, default='',
848 dest='post_user', metavar='post_user', type='string',
849 help='Specify a user to execute the post script.')
850 (options, pathnames) = parser.parse_args()
852 if not options.runfile and not options.template:
853 options.cmd = 'runtests'
855 if options.runfile and len(pathnames):
856 fail('Extraneous arguments.')
858 options.pathnames = [os.path.abspath(path) for path in pathnames]
864 options = parse_args()
865 testrun = TestRun(options)
867 if options.cmd is 'runtests':
868 find_tests(testrun, options)
869 elif options.cmd is 'rdconfig':
870 testrun.read(testrun.logger, options)
871 elif options.cmd is 'wrconfig':
872 find_tests(testrun, options)
873 testrun.write(options)
876 fail('Unknown command specified')
878 testrun.complete_outputdirs()
884 if __name__ == '__main__':