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, stdin=PIPE)
236 # Allow a special timeout value of 0 to mean infinity
237 if int(self.timeout) == 0:
238 self.timeout = maxint
239 t = Timer(int(self.timeout), self.kill_cmd, [proc])
241 self.result.stdout, self.result.stderr = self.collect_output(proc)
242 except KeyboardInterrupt:
244 fail('\nRun terminated at user request.')
248 self.result.done(proc, self.killed)
252 Initialize enough of the test result that we can log a skipped
256 Result.runresults['SKIP'] += 1
257 self.result.stdout = self.result.stderr = []
258 self.result.starttime = time()
259 m, s = divmod(time() - self.result.starttime, 60)
260 self.result.runtime = '%02d:%02d' % (m, s)
261 self.result.result = 'SKIP'
263 def log(self, logger, options):
265 This function is responsible for writing all output. This includes
266 the console output, the logfile of all results (with timestamped
267 merged stdout and stderr), and for each test, the unmodified
268 stdout/stderr/merged in it's own file.
273 logname = getpwuid(os.getuid()).pw_name
274 user = ' (run as %s)' % (self.user if len(self.user) else logname)
275 msga = 'Test: %s%s ' % (self.pathname, user)
276 msgb = '[%s] [%s]' % (self.result.runtime, self.result.result)
277 pad = ' ' * (80 - (len(msga) + len(msgb)))
279 # If -q is specified, only print a line for tests that didn't pass.
280 # This means passing tests need to be logged as DEBUG, or the one
281 # line summary will only be printed in the logfile for failures.
282 if not options.quiet:
283 logger.info('%s%s%s' % (msga, pad, msgb))
284 elif self.result.result is not 'PASS':
285 logger.info('%s%s%s' % (msga, pad, msgb))
287 logger.debug('%s%s%s' % (msga, pad, msgb))
289 lines = sorted(self.result.stdout + self.result.stderr,
290 cmp=lambda x, y: cmp(x[0], y[0]))
292 for dt, line in lines:
293 logger.debug('%s %s' % (dt.strftime("%H:%M:%S.%f ")[:11], line))
295 if len(self.result.stdout):
296 with open(os.path.join(self.outputdir, 'stdout'), 'w') as out:
297 for _, line in self.result.stdout:
298 os.write(out.fileno(), '%s\n' % line)
299 if len(self.result.stderr):
300 with open(os.path.join(self.outputdir, 'stderr'), 'w') as err:
301 for _, line in self.result.stderr:
302 os.write(err.fileno(), '%s\n' % line)
303 if len(self.result.stdout) and len(self.result.stderr):
304 with open(os.path.join(self.outputdir, 'merged'), 'w') as merged:
305 for _, line in lines:
306 os.write(merged.fileno(), '%s\n' % line)
310 props = ['outputdir', 'timeout', 'user', 'pre', 'pre_user', 'post',
313 def __init__(self, pathname, outputdir=None, timeout=None, user=None,
314 pre=None, pre_user=None, post=None, post_user=None):
315 super(Test, self).__init__(pathname, outputdir, timeout, user)
317 self.pre_user = pre_user or ''
318 self.post = post or ''
319 self.post_user = post_user or ''
322 post_user = pre_user = ''
323 if len(self.pre_user):
324 pre_user = ' (as %s)' % (self.pre_user)
325 if len(self.post_user):
326 post_user = ' (as %s)' % (self.post_user)
327 return "Pathname: %s\nOutputdir: %s\nTimeout: %d\nPre: %s%s\nPost: " \
328 "%s%s\nUser: %s\n" % \
329 (self.pathname, self.outputdir, self.timeout, self.pre,
330 pre_user, self.post, post_user, self.user)
332 def verify(self, logger):
334 Check the pre/post scripts, user and Test. Omit the Test from this
335 run if there are any problems.
337 files = [self.pre, self.pathname, self.post]
338 users = [self.pre_user, self.user, self.post_user]
340 for f in [f for f in files if len(f)]:
341 if not verify_file(f):
342 logger.info("Warning: Test '%s' not added to this run because"
343 " it failed verification." % f)
346 for user in [user for user in users if len(user)]:
347 if not verify_user(user, logger):
348 logger.info("Not adding Test '%s' to this run." %
354 def run(self, logger, options):
356 Create Cmd instances for the pre/post scripts. If the pre script
357 doesn't pass, skip this Test. Run the post script regardless.
359 odir = os.path.join(self.outputdir, os.path.basename(self.pre))
360 pretest = Cmd(self.pre, outputdir=odir, timeout=self.timeout,
362 test = Cmd(self.pathname, outputdir=self.outputdir,
363 timeout=self.timeout, user=self.user)
364 odir = os.path.join(self.outputdir, os.path.basename(self.post))
365 posttest = Cmd(self.post, outputdir=odir, timeout=self.timeout,
369 if len(pretest.pathname):
371 cont = pretest.result.result is 'PASS'
372 pretest.log(logger, options)
379 test.log(logger, options)
381 if len(posttest.pathname):
382 posttest.run(options)
383 posttest.log(logger, options)
386 class TestGroup(Test):
387 props = Test.props + ['tests']
389 def __init__(self, pathname, outputdir=None, timeout=None, user=None,
390 pre=None, pre_user=None, post=None, post_user=None,
392 super(TestGroup, self).__init__(pathname, outputdir, timeout, user,
393 pre, pre_user, post, post_user)
394 self.tests = tests or []
397 post_user = pre_user = ''
398 if len(self.pre_user):
399 pre_user = ' (as %s)' % (self.pre_user)
400 if len(self.post_user):
401 post_user = ' (as %s)' % (self.post_user)
402 return "Pathname: %s\nOutputdir: %s\nTests: %s\nTimeout: %d\n" \
403 "Pre: %s%s\nPost: %s%s\nUser: %s\n" % \
404 (self.pathname, self.outputdir, self.tests, self.timeout,
405 self.pre, pre_user, self.post, post_user, self.user)
407 def verify(self, logger):
409 Check the pre/post scripts, user and tests in this TestGroup. Omit
410 the TestGroup entirely, or simply delete the relevant tests in the
411 group, if that's all that's required.
413 # If the pre or post scripts are relative pathnames, convert to
414 # absolute, so they stand a chance of passing verification.
415 if len(self.pre) and not os.path.isabs(self.pre):
416 self.pre = os.path.join(self.pathname, self.pre)
417 if len(self.post) and not os.path.isabs(self.post):
418 self.post = os.path.join(self.pathname, self.post)
420 auxfiles = [self.pre, self.post]
421 users = [self.pre_user, self.user, self.post_user]
423 for f in [f for f in auxfiles if len(f)]:
424 if self.pathname != os.path.dirname(f):
425 logger.info("Warning: TestGroup '%s' not added to this run. "
426 "Auxiliary script '%s' exists in a different "
427 "directory." % (self.pathname, f))
430 if not verify_file(f):
431 logger.info("Warning: TestGroup '%s' not added to this run. "
432 "Auxiliary script '%s' failed verification." %
436 for user in [user for user in users if len(user)]:
437 if not verify_user(user, logger):
438 logger.info("Not adding TestGroup '%s' to this run." %
442 # If one of the tests is invalid, delete it, log it, and drive on.
443 self.tests[:] = [f for f in self.tests if
444 verify_file(os.path.join(self.pathname, f))]
446 return len(self.tests) is not 0
448 def run(self, logger, options):
450 Create Cmd instances for the pre/post scripts. If the pre script
451 doesn't pass, skip all the tests in this TestGroup. Run the post
454 odir = os.path.join(self.outputdir, os.path.basename(self.pre))
455 pretest = Cmd(self.pre, outputdir=odir, timeout=self.timeout,
457 odir = os.path.join(self.outputdir, os.path.basename(self.post))
458 posttest = Cmd(self.post, outputdir=odir, timeout=self.timeout,
462 if len(pretest.pathname):
464 cont = pretest.result.result is 'PASS'
465 pretest.log(logger, options)
467 for fname in self.tests:
468 test = Cmd(os.path.join(self.pathname, fname),
469 outputdir=os.path.join(self.outputdir, fname),
470 timeout=self.timeout, user=self.user)
476 test.log(logger, options)
478 if len(posttest.pathname):
479 posttest.run(options)
480 posttest.log(logger, options)
483 class TestRun(object):
484 props = ['quiet', 'outputdir']
486 def __init__(self, options):
489 self.starttime = time()
490 self.timestamp = datetime.now().strftime('%Y%m%dT%H%M%S')
491 self.outputdir = os.path.join(options.outputdir, self.timestamp)
492 self.logger = self.setup_logging(options)
494 ('outputdir', BASEDIR),
505 s = 'TestRun:\n outputdir: %s\n' % self.outputdir
507 for key in sorted(self.tests.keys()):
508 s += '%s%s' % (self.tests[key].__str__(), '\n')
510 for key in sorted(self.testgroups.keys()):
511 s += '%s%s' % (self.testgroups[key].__str__(), '\n')
514 def addtest(self, pathname, options):
516 Create a new Test, and apply any properties that were passed in
517 from the command line. If it passes verification, add it to the
520 test = Test(pathname)
521 for prop in Test.props:
522 setattr(test, prop, getattr(options, prop))
524 if test.verify(self.logger):
525 self.tests[pathname] = test
527 def addtestgroup(self, dirname, filenames, options):
529 Create a new TestGroup, and apply any properties that were passed
530 in from the command line. If it passes verification, add it to the
533 if dirname not in self.testgroups:
534 testgroup = TestGroup(dirname)
535 for prop in Test.props:
536 setattr(testgroup, prop, getattr(options, prop))
538 # Prevent pre/post scripts from running as regular tests
539 for f in [testgroup.pre, testgroup.post]:
541 del filenames[filenames.index(f)]
543 self.testgroups[dirname] = testgroup
544 self.testgroups[dirname].tests = sorted(filenames)
546 testgroup.verify(self.logger)
548 def read(self, logger, options):
550 Read in the specified runfile, and apply the TestRun properties
551 listed in the 'DEFAULT' section to our TestRun. Then read each
552 section, and apply the appropriate properties to the Test or
553 TestGroup. Properties from individual sections override those set
554 in the 'DEFAULT' section. If the Test or TestGroup passes
555 verification, add it to the TestRun.
557 config = ConfigParser.RawConfigParser()
558 if not len(config.read(options.runfile)):
559 fail("Coulnd't read config file %s" % options.runfile)
561 for opt in TestRun.props:
562 if config.has_option('DEFAULT', opt):
563 setattr(self, opt, config.get('DEFAULT', opt))
564 self.outputdir = os.path.join(self.outputdir, self.timestamp)
566 for section in config.sections():
567 if 'tests' in config.options(section):
568 testgroup = TestGroup(section)
569 for prop in TestGroup.props:
570 for sect in ['DEFAULT', section]:
571 if config.has_option(sect, prop):
572 setattr(testgroup, prop, config.get(sect, prop))
574 # Repopulate tests using eval to convert the string to a list
575 testgroup.tests = eval(config.get(section, 'tests'))
577 if testgroup.verify(logger):
578 self.testgroups[section] = testgroup
580 elif 'autotests' in config.options(section):
581 testgroup = TestGroup(section)
582 for prop in TestGroup.props:
583 for sect in ['DEFAULT', section]:
584 if config.has_option(sect, prop):
585 setattr(testgroup, prop, config.get(sect, prop))
587 filenames = os.listdir(section)
588 # only files starting with "tst." are considered tests
589 filenames = [f for f in filenames if f.startswith("tst.")]
590 testgroup.tests = sorted(filenames)
592 if testgroup.verify(logger):
593 self.testgroups[section] = testgroup
597 for prop in Test.props:
598 for sect in ['DEFAULT', section]:
599 if config.has_option(sect, prop):
600 setattr(test, prop, config.get(sect, prop))
602 if test.verify(logger):
603 self.tests[section] = test
605 def write(self, options):
607 Create a configuration file for editing and later use. The
608 'DEFAULT' section of the config file is created from the
609 properties that were specified on the command line. Tests are
610 simply added as sections that inherit everything from the
611 'DEFAULT' section. TestGroups are the same, except they get an
612 option including all the tests to run in that directory.
615 defaults = dict([(prop, getattr(options, prop)) for prop, _ in
617 config = ConfigParser.RawConfigParser(defaults)
619 for test in sorted(self.tests.keys()):
620 config.add_section(test)
622 for testgroup in sorted(self.testgroups.keys()):
623 config.add_section(testgroup)
624 config.set(testgroup, 'tests', self.testgroups[testgroup].tests)
627 with open(options.template, 'w') as f:
628 return config.write(f)
630 fail('Could not open \'%s\' for writing.' % options.template)
632 def complete_outputdirs(self):
634 Collect all the pathnames for Tests, and TestGroups. Work
635 backwards one pathname component at a time, to create a unique
636 directory name in which to deposit test output. Tests will be able
637 to write output files directly in the newly modified outputdir.
638 TestGroups will be able to create one subdirectory per test in the
639 outputdir, and are guaranteed uniqueness because a group can only
640 contain files in one directory. Pre and post tests will create a
641 directory rooted at the outputdir of the Test or TestGroup in
642 question for their output.
646 tmp_dict = dict(self.tests.items() + self.testgroups.items())
647 total = len(tmp_dict)
648 base = self.outputdir
653 for testfile in tmp_dict.keys():
654 uniq = '/'.join(testfile.split('/')[components:]).lstrip('/')
657 tmp_dict[testfile].outputdir = os.path.join(base, uniq)
660 done = total == len(l)
662 def setup_logging(self, options):
664 Two loggers are set up here. The first is for the logfile which
665 will contain one line summarizing the test, including the test
666 name, result, and running time. This logger will also capture the
667 timestamped combined stdout and stderr of each run. The second
668 logger is optional console output, which will contain only the one
669 line summary. The loggers are initialized at two different levels
670 to facilitate segregating the output.
672 if options.dryrun is True:
675 testlogger = logging.getLogger(__name__)
676 testlogger.setLevel(logging.DEBUG)
678 if options.cmd is not 'wrconfig':
681 os.makedirs(self.outputdir, mode=0777)
685 filename = os.path.join(self.outputdir, 'log')
687 logfile = WatchedFileHandlerClosed(filename)
688 logfile.setLevel(logging.DEBUG)
689 logfilefmt = logging.Formatter('%(message)s')
690 logfile.setFormatter(logfilefmt)
691 testlogger.addHandler(logfile)
693 cons = logging.StreamHandler()
694 cons.setLevel(logging.INFO)
695 consfmt = logging.Formatter('%(message)s')
696 cons.setFormatter(consfmt)
697 testlogger.addHandler(cons)
701 def run(self, options):
703 Walk through all the Tests and TestGroups, calling run().
705 if not options.dryrun:
707 os.chdir(self.outputdir)
709 fail('Could not change to directory %s' % self.outputdir)
710 for test in sorted(self.tests.keys()):
711 self.tests[test].run(self.logger, options)
712 for testgroup in sorted(self.testgroups.keys()):
713 self.testgroups[testgroup].run(self.logger, options)
716 if Result.total is 0:
719 print '\nResults Summary'
720 for key in Result.runresults.keys():
721 if Result.runresults[key] is not 0:
722 print '%s\t% 4d' % (key, Result.runresults[key])
724 m, s = divmod(time() - self.starttime, 60)
726 print '\nRunning Time:\t%02d:%02d:%02d' % (h, m, s)
727 print 'Percent passed:\t%.1f%%' % ((float(Result.runresults['PASS']) /
728 float(Result.total)) * 100)
729 print 'Log directory:\t%s' % self.outputdir
732 def verify_file(pathname):
734 Verify that the supplied pathname is an executable regular file.
736 if os.path.isdir(pathname) or os.path.islink(pathname):
739 if os.path.isfile(pathname) and os.access(pathname, os.X_OK):
745 def verify_user(user, logger):
747 Verify that the specified user exists on this system, and can execute
748 sudo without being prompted for a password.
750 testcmd = [SUDO, '-n', '-u', user, TRUE]
752 if user in Cmd.verified_users:
758 logger.info("Warning: user '%s' does not exist.", user)
763 if p.returncode is not 0:
764 logger.info("Warning: user '%s' cannot use passwordless sudo.", user)
767 Cmd.verified_users.append(user)
772 def find_tests(testrun, options):
774 For the given list of pathnames, add files as Tests. For directories,
775 if do_groups is True, add the directory as a TestGroup. If False,
776 recursively search for executable files.
779 for p in sorted(options.pathnames):
781 for dirname, _, filenames in os.walk(p):
782 if options.do_groups:
783 testrun.addtestgroup(dirname, filenames, options)
785 for f in sorted(filenames):
786 testrun.addtest(os.path.join(dirname, f), options)
788 testrun.addtest(p, options)
791 def fail(retstr, ret=1):
792 print '%s: %s' % (argv[0], retstr)
796 def options_cb(option, opt_str, value, parser):
797 path_options = ['runfile', 'outputdir', 'template']
799 if option.dest is 'runfile' and '-w' in parser.rargs or \
800 option.dest is 'template' and '-c' in parser.rargs:
801 fail('-c and -w are mutually exclusive.')
803 if opt_str in parser.rargs:
804 fail('%s may only be specified once.' % opt_str)
806 if option.dest is 'runfile':
807 parser.values.cmd = 'rdconfig'
808 if option.dest is 'template':
809 parser.values.cmd = 'wrconfig'
811 setattr(parser.values, option.dest, value)
812 if option.dest in path_options:
813 setattr(parser.values, option.dest, os.path.abspath(value))
817 parser = OptionParser()
818 parser.add_option('-c', action='callback', callback=options_cb,
819 type='string', dest='runfile', metavar='runfile',
820 help='Specify tests to run via config file.')
821 parser.add_option('-d', action='store_true', default=False, dest='dryrun',
822 help='Dry run. Print tests, but take no other action.')
823 parser.add_option('-g', action='store_true', default=False,
824 dest='do_groups', help='Make directories TestGroups.')
825 parser.add_option('-o', action='callback', callback=options_cb,
826 default=BASEDIR, dest='outputdir', type='string',
827 metavar='outputdir', help='Specify an output directory.')
828 parser.add_option('-p', action='callback', callback=options_cb,
829 default='', dest='pre', metavar='script',
830 type='string', help='Specify a pre script.')
831 parser.add_option('-P', action='callback', callback=options_cb,
832 default='', dest='post', metavar='script',
833 type='string', help='Specify a post script.')
834 parser.add_option('-q', action='store_true', default=False, dest='quiet',
835 help='Silence on the console during a test run.')
836 parser.add_option('-t', action='callback', callback=options_cb, default=60,
837 dest='timeout', metavar='seconds', type='int',
838 help='Timeout (in seconds) for an individual test.')
839 parser.add_option('-u', action='callback', callback=options_cb,
840 default='', dest='user', metavar='user', type='string',
841 help='Specify a different user name to run as.')
842 parser.add_option('-w', action='callback', callback=options_cb,
843 default=None, dest='template', metavar='template',
844 type='string', help='Create a new config file.')
845 parser.add_option('-x', action='callback', callback=options_cb, default='',
846 dest='pre_user', metavar='pre_user', type='string',
847 help='Specify a user to execute the pre script.')
848 parser.add_option('-X', action='callback', callback=options_cb, default='',
849 dest='post_user', metavar='post_user', type='string',
850 help='Specify a user to execute the post script.')
851 (options, pathnames) = parser.parse_args()
853 if not options.runfile and not options.template:
854 options.cmd = 'runtests'
856 if options.runfile and len(pathnames):
857 fail('Extraneous arguments.')
859 options.pathnames = [os.path.abspath(path) for path in pathnames]
865 options = parse_args()
866 testrun = TestRun(options)
868 if options.cmd is 'runtests':
869 find_tests(testrun, options)
870 elif options.cmd is 'rdconfig':
871 testrun.read(testrun.logger, options)
872 elif options.cmd is 'wrconfig':
873 find_tests(testrun, options)
874 testrun.write(options)
877 fail('Unknown command specified')
879 testrun.complete_outputdirs()
885 if __name__ == '__main__':