Beispiel #1
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    parser.add_argument("--verbose", "-v", action="count", default=0)

    parser.add_argument("directories", metavar="DIRECTORY", nargs="+",
                        help="a testsuite directory, a TESTLIST file, or a list of test directories")
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    logutil.add_arguments(parser)
    skip.add_arguments(parser)
    ignore.add_arguments(parser)
    publish.add_arguments(parser)

    # These three calls go together
    args = parser.parse_args()
    logutil.config(args, sys.stdout)
    logger = logutil.getLogger("kvmrunner")

    logger.info("Options:")
    logger.info("  directories: %s", args.directories)
    logger.info("  verbose: %s", args.verbose)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    logutil.log_arguments(logger, args)
    skip.log_arguments(logger, args)
    ignore.log_arguments(logger, args)
    publish.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger, args.directories, args,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directories)
        return 1

    test_stats = stats.Tests()
    result_stats = stats.Results()

    try:
        exit_code = 0
        logger.info("run started at %s", timing.START_TIME)
        runner.run_tests(logger, args, tests, test_stats, result_stats)
    except KeyboardInterrupt:
        logger.exception("**** interrupted ****")
        exit_code = 1

    test_stats.log_details(args.verbose and logger.info or logger.debug,
                           header="final stat details:", prefix="  ")
    result_stats.log_details(logger.info, header="final test details:", prefix="  ")

    test_stats.log_summary(logger.info, header="final test stats:", prefix="  ")
    result_stats.log_summary(logger.info, header="final test results:", prefix="  ")

    end_time = datetime.now()
    logger.info("run finished at %s after %s", end_time, end_time - timing.START_TIME)

    return exit_code
Beispiel #2
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    parser.add_argument("--verbose", "-v", action="count", default=0)

    parser.add_argument("directories", metavar="DIRECTORY", nargs="+",
                        help="a testsuite directory, a TESTLIST file, or a list of test directories")
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    post.add_arguments(parser)
    logutil.add_arguments(parser)
    skip.add_arguments(parser)
    ignore.add_arguments(parser)

    args = parser.parse_args()
    logutil.config(args)

    logger = logutil.getLogger("kvmrunner")
    logger.info("Options:")
    logger.info("  directories: %s", args.directories)
    logger.info("  verbose: %s", args.verbose)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    post.log_arguments(logger, args)
    logutil.log_arguments(logger, args)
    skip.log_arguments(logger, args)
    ignore.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger, args.directories, args,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directories)
        return 1

    test_stats = stats.Tests()
    result_stats = stats.Results()

    try:
        exit_code = 0
        logger.info("run started at %s", timing.START_TIME)
        runner.run_tests(logger, args, tests, test_stats, result_stats)
    except KeyboardInterrupt:
        logger.exception("**** interrupted ****")
        exit_code = 1

    test_stats.log_details(args.verbose and logger.info or logger.debug,
                           header="final stat details:", prefix="  ")
    result_stats.log_details(logger.info, header="final test details:", prefix="  ")

    test_stats.log_summary(logger.info, header="final test stats:", prefix="  ")
    result_stats.log_summary(logger.info, header="final test results:", prefix="  ")

    end_time = datetime.now()
    logger.info("run finished at %s after %s", end_time, end_time - timing.START_TIME)

    return exit_code
Beispiel #3
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    # This argument's behaviour is overloaded; the shorter word "try"
    # is a python word.
    parser.add_argument(
        "--retry",
        type=int,
        metavar="COUNT",
        help=
        ("number of times a test should be attempted before giving up"
         " (tests are categorised as not-started (no OUTPUT directory), incomplete, failed, passed)"
         "; a negative %(metavar)s selects all tests"
         "; a zero %(metavar)s selects not-started tests"
         "; a positive %(metavar)s selects not-started, incomplete and failing tests"
         "; default is to select not-started tests"))
    parser.add_argument("--dry-run", "-n", action="store_true")
    parser.add_argument("--verbose", "-v", action="count", default=0)
    parser.add_argument("directories",
                        metavar="DIRECTORY",
                        nargs="*",
                        help=("Either a testsuite directory or"
                              " a list of test directories"))
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    post.add_arguments(parser)
    logutil.add_arguments(parser)

    args = parser.parse_args()
    logutil.config(args)

    logger = logutil.getLogger("kvmrunner")
    logger.info("Options:")
    logger.info("  retry: %s", args.retry or "0 (default)")
    logger.info("  dry-run: %s", args.dry_run)
    logger.info("  directories: %s", args.directories)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    post.log_arguments(logger, args)
    logutil.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger,
                                              args.directories,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directory)
        return 1

    # A list of test directories was specified (i.e, not a testsuite),
    # then force the tests to run.
    if isinstance(tests, list) and args.retry is None:
        args.retry = 1
        logger.info(
            "Explicit directory list; forcing --retry=%d (retry failed tests)",
            args.retry)

    # Use a default dict so no need to worry about initializing values
    # to zero.
    stats = Stats()
    results = Results()
    start_time = time.localtime()

    try:
        logger.info("run started at %s", datetime.now())

        for test in tests:
            stats.add("total", test)

            ignore = testsuite.ignore(test, args)
            if ignore:
                stats.add("ignored", test)
                # No need to log all the ignored tests when an
                # explicit sub-set of tests is being run.  For
                # instance, when running just one test.
                if not args.test_name:
                    logger.info("*** %s: ignore (%s)", test.name, ignore)
                continue

            # Implement "--retry" as described above: if retry is -ve,
            # the test is always run; if there's no result, the test
            # is always run; skip passed tests; else things get a
            # little wierd.
            retry = args.retry or 0
            if retry >= 0:
                result = post.mortem(test, args)
                if result:
                    if result.passed:
                        logger.info("*** %s: passed", test.name)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
                    if retry == 0:
                        logger.info("*** %s: %s (delete '%s' to re-test)",
                                    test.name, result.value,
                                    test.output_directory)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
            stats.add("tests", test)

            debugfile = None
            result = None

            # At least one iteration; above will have filtered out
            # skips and ignores
            runs = max(abs(retry), 1)
            for run in range(runs):
                stats.add("runs", test)

                # Create an output directory.  If there's already an
                # existing OUTPUT directory rename it to OUTPUT...
                # Need to do this before the OUTPUT/debug.log is
                # started as otherwise it too would get moved away.
                saved_output_directory = None
                if not args.dry_run:
                    try:
                        os.mkdir(test.output_directory)
                    except FileExistsError:
                        stats.add("reruns", test)
                        # Include the time this test run started in
                        # the suffix - that way all saved results can
                        # be matched using a wild card.  Include the
                        # time the directory was last modified in the
                        # suffix - it makes a good approximation as to
                        # when the previous test run finished.
                        stat = os.stat(test.output_directory)
                        mtime = time.localtime(
                            os.stat(test.output_directory).st_mtime)
                        saved_output_directory = (
                            test.output_directory +
                            time.strftime(".%Y%m%d%H%M", start_time) +
                            time.strftime(".%H%M%S", mtime))
                        logger.debug("renaming '%s' to '%s'",
                                     test.output_directory,
                                     saved_output_directory)
                        os.rename(test.output_directory,
                                  saved_output_directory)
                        # if the second attempt fails, let it crash
                        os.mkdir(test.output_directory)

                # Start a debug log in the OUTPUT directory; include
                # timing for this specific test run.
                with logutil.TIMER, logutil.Debug(
                        logger, os.path.join(test.output_directory,
                                             "debug.log")):
                    logger.info(
                        "****** test %s attempt %d of %d started at %s ******",
                        test.name, run + 1, runs, datetime.now())
                    # Add a log message about any saved output
                    # directory to the per-test-run debug log.  It
                    # just looks better.
                    if saved_output_directory:
                        logger.info("existing OUTPUT saved in '%s'",
                                    saved_output_directory)
                    ending = "undefined"
                    try:
                        if not args.dry_run:
                            runner.run_test(test, max_workers=args.workers)
                        ending = "finished"
                        result = post.mortem(test,
                                             args,
                                             update=(not args.dry_run))
                        if not args.dry_run:
                            # Store enough to fool the script
                            # pluto-testlist-scan.sh.
                            logger.info("storing result in '%s'",
                                        test.result_file)
                            with open(test.result_file, "w") as f:
                                f.write('"result": "')
                                f.write(result.value)
                                f.write('"')
                                f.write("\n")
                    except pexpect.TIMEOUT as e:
                        ending = "timeout"
                        logger.exception("**** test %s timed out ****",
                                         test.name)
                        result = post.mortem(test,
                                             args,
                                             update=(not args.dry_run))
                    # Since the OUTPUT directory exists, all paths to
                    # here should have a non-null RESULT.
                    stats.add("runs(%s:%s)" % (ending, result.value), test)
                    logger.info("****** test %s %s ******", test.name, result)
                    if result.passed:
                        break

            # Above will have set RESULT (don't reach here during
            # cntrl-c or crash).
            results.add(result)
            stats.add("tests(%s)" % result.value, test)

    except KeyboardInterrupt:
        logger.exception("**** test %s interrupted ****", test.name)
        return 1

    finally:
        logger.info("run finished at %s", datetime.now())

        level = args.verbose and logutil.INFO or logutil.DEBUG
        logger.log(level, "stat details:")
        stats.log_details(logger, level=level, prefix="  ")

        logger.info("result details:")
        results.log_details(logger, level=logutil.INFO, prefix="  ")

        logger.info("stat summary:")
        stats.log_summary(logger, level=logutil.INFO, prefix="  ")
        logger.info("result summary:")
        results.log_summary(logger, level=logutil.INFO, prefix="  ")

    return 0
Beispiel #4
0
def main():

    # If SIGUSR1, backtrace all threads; hopefully this is early
    # enough.
    faulthandler.register(signal.SIGUSR1)

    parser = argparse.ArgumentParser(
        description="Run tests", epilog="SIGUSR1 will dump all thread stacks")

    parser.add_argument("--verbose", "-v", action="count", default=0)
    parser.add_argument("--pid-file",
                        default="",
                        help="file to store process id of KVMRUNNER")

    parser.add_argument(
        "directories",
        metavar="DIRECTORY",
        nargs="+",
        help=
        "a testsuite directory, a TESTLIST file, or a list of test directories"
    )
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    logutil.add_arguments(parser)
    skip.add_arguments(parser)
    ignore.add_arguments(parser)
    publish.add_arguments(parser)

    # These three calls go together
    args = parser.parse_args()
    logutil.config(args, sys.stdout)
    logger = logutil.getLogger("kvmrunner")

    logger.info("Options:")
    logger.info("  directories: %s", args.directories)
    logger.info("  verbose: %s", args.verbose)
    logger.info("  pid-file: %s", args.pid_file)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    logutil.log_arguments(logger, args)
    skip.log_arguments(logger, args)
    ignore.log_arguments(logger, args)
    publish.log_arguments(logger, args)

    if args.pid_file:
        pid = os.getpid()
        logger.info("writing pid %d to '%s'", pid, args.pid_file)
        with open(args.pid_file, "wt") as pidfile:
            pidfile.write("%d\n" % os.getpid())

    tests = testsuite.load_testsuite_or_tests(logger,
                                              args.directories,
                                              args,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s",
                     args.directories)
        return 1

    if len(tests) == 1 and args.run_post_mortem is None:
        logger.warning(
            "skipping post-mortem.sh as only one test; use --run-post-mortem true to override this"
        )
        args.run_post_mortem = False

    test_stats = stats.Tests()
    result_stats = stats.Results()

    try:
        exit_code = 0
        logger.info("run started at %s", timing.START_TIME)
        runner.run_tests(logger, args, tests, test_stats, result_stats)
    except KeyboardInterrupt:
        logger.exception("**** interrupted ****")
        exit_code = 1

    test_stats.log_details(args.verbose and logger.info or logger.debug,
                           header="final stat details:",
                           prefix="  ")
    result_stats.log_details(logger.info,
                             header="final test details:",
                             prefix="  ")

    test_stats.log_summary(logger.info,
                           header="final test stats:",
                           prefix="  ")
    result_stats.log_summary(logger.info,
                             header="final test results:",
                             prefix="  ")

    stop_time = datetime.now()
    logger.info("run finished at %s after %s", stop_time,
                stop_time - timing.START_TIME)

    return exit_code
Beispiel #5
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    # This argument's behaviour is overloaded; the shorter word "try"
    # is a python word.
    parser.add_argument("--retry", type=int, metavar="COUNT", default=1,
                        help="which previously run tests should be retried: 0 selects not-started tests; 1 selects not-started+failed tests; -1 selects not-started+failed+passed tests (default is %(default)s)")
    parser.add_argument("--attempts", type=int, default=1,
                        help="number of times to attempt a test before giving up; default %(default)s")

    parser.add_argument("--dry-run", "-n", action="store_true")
    parser.add_argument("--verbose", "-v", action="count", default=0)

    # Default to BACKUP under the current directory.  Name is
    # arbitrary, chosen for its hopefully unique first letter
    # (avoiding Makefile, OBJ, README, ... :-).
    parser.add_argument("--backup-directory", metavar="DIRECTORY", default="BACKUP",
                        help="backup existing <test>/OUTPUT to %(metavar)s/<date>/<test> (default: %(default)s)")

    parser.add_argument("directories", metavar="DIRECTORY", nargs="+",
                        help="either a testsuite directory or a list of test directories")
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    post.add_arguments(parser)
    logutil.add_arguments(parser)

    args = parser.parse_args()
    logutil.config(args)

    logger = logutil.getLogger("kvmrunner")
    logger.info("Options:")
    logger.info("  retry: %s", args.retry)
    logger.info("  attempts: %s", args.attempts)
    logger.info("  dry-run: %s", args.dry_run)
    logger.info("  backup-directory: %s", args.backup_directory)
    logger.info("  directories: %s", args.directories)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    post.log_arguments(logger, args)
    logutil.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger, args.directories, args,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directories)
        return 1

    test_stats = stats.Tests()
    result_stats = stats.Results()

    start_time = datetime.now()
    exit_code = 0

    try:
        logger.info("run started at %s", start_time)

        test_count = 0
        for test in tests:

            test_stats.add(test, "total")
            test_count += 1
            # Would the number of tests to be [re]run be better?
            test_prefix = "****** %s (test %d of %d)" % (test.name, test_count, len(tests))

            ignore, details = testsuite.ignore(test, args)
            if ignore:
                result_stats.add_ignored(test, ignore)
                test_stats.add(test, "ignored")
                # No need to log all the ignored tests when an
                # explicit sub-set of tests is being run.  For
                # instance, when running just one test.
                if not args.test_name:
                    logger.info("%s: ignore (%s)", test_prefix, details)
                continue

            # Implement "--retry" as described above: if retry is -ve,
            # the test is always run; if there's no result, the test
            # is always run; skip passed tests; else things get a
            # little wierd.

            # Be lazy with gathering the results, don't run the
            # sanitizer or diff.
            old_result = post.mortem(test, args, skip_diff=True, skip_sanitize=True)
            if args.retry >= 0:
                if old_result:
                    if old_result.passed:
                        logger.info("%s: passed", test_prefix)
                        test_stats.add(test, "skipped")
                        result_stats.add_skipped(old_result)
                        continue
                    if args.retry == 0:
                        logger.info("%s: %s (delete '%s' to re-test)", test_prefix,
                                    result, test.output_directory)
                        test_stats.add(test, "skipped")
                        result_stats.add_skipped(old_result)
                        continue
                    test_stats.add(test, "retry")

            logger.info("%s: starting ...", test_prefix)
            test_stats.add(test, "tests")

            # Move the contents of the existing OUTPUT directory to
            # BACKUP_DIRECTORY.  Do it file-by-file so that, at no
            # point, the directory is empty.
            #
            # By moving each test just before it is started a trail of
            # what tests were attempted at each run is left.
            #
            # XXX: During boot, swan-transmogrify runs "chcon -R
            # testing/pluto".  Of course this means that each time a
            # test is added and/or a test is run (adding files under
            # <test>/OUTPUT), the boot process (and consequently the
            # time taken to run a test) keeps increasing.
            #
            # Always moving the directory contents to the
            # BACKUP_DIRECTORY mitigates this some.

            saved_output_directory = None
            if os.path.exists(test.output_directory):
                saved_output_directory = os.path.join(args.backup_directory,
                                                      start_time.strftime("%Y%m%d%H%M%S"),
                                                      test.name)
                logger.info("moving contents of '%s' to '%s'",
                            test.output_directory, saved_output_directory)
                # Copy "empty" OUTPUT directories too.
                args.dry_run or os.makedirs(saved_output_directory, exist_ok=True)
                for name in os.listdir(test.output_directory):
                    src = os.path.join(test.output_directory, name)
                    dst = os.path.join(saved_output_directory, name)
                    logger.debug("moving '%s' to '%s'", src, dst)
                    args.dry_run or os.replace(src, dst)

            debugfile = None
            result = None

            # At least one iteration; above will have filtered out
            # skips and ignores
            for attempt in range(args.attempts):
                test_stats.add(test, "attempts")

                # Create the OUTPUT directory.
                try:
                    if not args.dry_run:
                        os.mkdir(test.output_directory)
                    elif os.exists(test.output_directory):
                        raise FileExistsError()
                except FileExistsError:
                    # On first attempt, the OUTPUT directory will
                    # be empty (see above) so no need to save.
                    if attempt > 0:
                        saved_output_directory = os.path.join(test.output_directory, str(attempt))
                        logger.info("moving contents of '%s' to '%s'",
                                    test.output_directory, saved_output_directory)
                        args.dry_run or os.makedirs(saved_output_directory, exist_ok=True)
                        for name in os.listdir(test.output_directory):
                            if os.path.isfile(src):
                                src = os.path.join(test.output_directory, name)
                                dst = os.path.join(saved_output_directory, name)
                                logger.debug("moving '%s' to '%s'", src, dst)
                                args.dry_run or os.replace(src, dst)

                # Start a debug log in the OUTPUT directory; include
                # timing for this specific test attempt.
                with logutil.TIMER, logutil.Debug(logger, os.path.join(test.output_directory, "debug.log")):
                    logger.info("****** test %s attempt %d of %d started at %s ******",
                                test.name, attempt+1, args.attempts, datetime.now())

                    if saved_output_directory:
                        logger.info("contents of '%s' moved to '%s'",
                                    test.output_directory, saved_output_directory)
                    saved_output_directory = None

                    ending = "undefined"
                    try:
                        if not args.dry_run:
                            runner.run_test(test, args)
                        ending = "finished"
                        result = post.mortem(test, args, update=(not args.dry_run))
                        if not args.dry_run:
                            # Store enough to fool the script
                            # pluto-testlist-scan.sh.
                            logger.info("storing result in '%s'", test.result_file)
                            with open(test.result_file, "w") as f:
                                f.write('"result": "%s"\n' % result)
                    except pexpect.TIMEOUT as e:
                        logger.exception("**** test %s timed out ****", test.name)
                        ending = "timed-out"
                        # If the test has no output to check against, this will "pass"
                        result = post.mortem(test, args, update=(not args.dry_run))
                    # Since the OUTPUT directory exists, all paths to
                    # here should have a non-null RESULT.
                    test_stats.add(test, "attempts", ending, str(result))
                    if result.errors:
                        logger.info("****** test %s %s %s ******", test.name, result, result.errors)
                    else:
                        logger.info("****** test %s %s ******", test.name, result)
                    if result.passed:
                        break

            # Above will have set RESULT.  During a control-c or crash
            # the below will not be executed.

            test_stats.add(test, "tests", str(result))
            result_stats.add_result(result, old_result)

            test_stats.log_summary(logger.info, header="updated test stats:", prefix="  ")
            result_stats.log_summary(logger.info, header="updated test results:", prefix="  ")

    except KeyboardInterrupt:
        logger.exception("**** test %s interrupted ****", test.name)
        exit_code = 1

    test_stats.log_details(args.verbose and logger.info or logger.debug,
                           header="final stat details:", prefix="  ")
    result_stats.log_details(logger.info, header="final test details:", prefix="  ")

    test_stats.log_summary(logger.info, header="final test stats:", prefix="  ")
    result_stats.log_summary(logger.info, header="final test results:", prefix="  ")

    end_time = datetime.now()
    logger.info("run finished at %s after %s", end_time, end_time - start_time)

    return exit_code
Beispiel #6
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    # This argument's behaviour is overloaded; the shorter word "try"
    # is a python word.
    parser.add_argument("--retry", type=int, metavar="COUNT", default=1,
                        help="which previously run tests should be retried: 0 selects not-started tests; 1 selects not-started+failed tests; -1 selects not-started+failed+passed tests (default is %(default)s)")
    parser.add_argument("--attempts", type=int, default=1,
                        help="number of times to attempt a test before giving up; default %(default)s")

    parser.add_argument("--dry-run", "-n", action="store_true")
    parser.add_argument("--verbose", "-v", action="count", default=0)

    # Default to BACKUP under the current directory.  Name is
    # arbitrary, chosen for its hopefully unique first letter
    # (avoiding Makefile, OBJ, README, ... :-).
    parser.add_argument("--backup-directory", metavar="DIRECTORY",
                        default=os.path.join("BACKUP", time.strftime("%Y%m%d%H%M%S", time.localtime())),
                        help="backup existing <test>/OUTPUT to %(metavar)s/<test> (default: %(default)s)")

    parser.add_argument("directories", metavar="DIRECTORY", nargs="+",
                        help="either a testsuite directory or a list of test directories")
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    post.add_arguments(parser)
    logutil.add_arguments(parser)

    args = parser.parse_args()
    logutil.config(args)

    logger = logutil.getLogger("kvmrunner")
    logger.info("Options:")
    logger.info("  retry: %s", args.retry)
    logger.info("  attempts: %s", args.attempts)
    logger.info("  dry-run: %s", args.dry_run)
    logger.info("  backup-directory: %s", args.backup_directory)
    logger.info("  directories: %s", args.directories)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    post.log_arguments(logger, args)
    logutil.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger, args.directories, args,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directories)
        return 1

    test_stats = stats.Tests()
    result_stats = stats.Results()

    start_time = datetime.now()

    try:
        logger.info("run started at %s", start_time)

        test_count = 0
        for test in tests:

            test_stats.add("total", test)
            test_count += 1
            # Would the number of tests to be [re]run be better?
            test_prefix = "****** %s (test %d of %d)" % (test.name, test_count, len(tests))

            ignore = testsuite.ignore(test, args)
            if ignore:
                result_stats.add_ignore(test, ignore)
                test_stats.add("ignored", test)
                # No need to log all the ignored tests when an
                # explicit sub-set of tests is being run.  For
                # instance, when running just one test.
                if not args.test_name:
                    logger.info("%s: ignore (%s)", test_prefix, ignore)
                continue

            # Implement "--retry" as described above: if retry is -ve,
            # the test is always run; if there's no result, the test
            # is always run; skip passed tests; else things get a
            # little wierd.

            # Be lazy with gathering the results, don't run the
            # sanitizer or diff.
            old_result = post.mortem(test, args, skip_diff=True, skip_sanitize=True)
            if args.retry >= 0:
                if old_result:
                    if old_result.passed:
                        logger.info("%s: passed", test_prefix)
                        test_stats.add("skipped", test)
                        result_stats.add_skip(old_result)
                        continue
                    if args.retry == 0:
                        logger.info("%s: %s (delete '%s' to re-test)", test_prefix,
                                    result, test.output_directory)
                        test_stats.add("skipped", test)
                        result_stats.add_skip(old_result)
                        continue
                    test_stats.add("retry", test)

            logger.info("%s: starting ...", test_prefix)
            test_stats.add("tests", test)

            # Move the contents of the existing OUTPUT directory to
            # BACKUP_DIRECTORY.  Do it file-by-file so that, at no
            # point, the directory is empty.
            #
            # By moving each test just before it is started a trail of
            # what tests were attempted at each run is left.
            #
            # XXX: During boot, swan-transmogrify runs "chcon -R
            # testing/pluto".  Of course this means that each time a
            # test is added and/or a test is run (adding files under
            # <test>/OUTPUT), the boot process (and consequently the
            # time taken to run a test) keeps increasing.
            #
            # Always moving the directory contents to the
            # BACKUP_DIRECTORY mitigates this some.

            saved_output_directory = None
            if os.path.exists(test.output_directory):
                saved_output_directory = os.path.join(args.backup_directory, test.name)
                logger.info("moving contents of '%s' to '%s'",
                            test.output_directory, saved_output_directory)
                # Copy "empty" OUTPUT directories too.
                args.dry_run or os.makedirs(saved_output_directory, exist_ok=True)
                for name in os.listdir(test.output_directory):
                    src = os.path.join(test.output_directory, name)
                    dst = os.path.join(saved_output_directory, name)
                    logger.debug("moving '%s' to '%s'", src, dst)
                    args.dry_run or os.replace(src, dst)

            debugfile = None
            result = None

            # At least one iteration; above will have filtered out
            # skips and ignores
            for attempt in range(args.attempts):
                test_stats.add("attempts", test)

                # Create the OUTPUT directory.
                try:
                    if not args.dry_run:
                        os.mkdir(test.output_directory)
                    elif os.exists(test.output_directory):
                        raise FileExistsError()
                except FileExistsError:
                    # On first attempt, the OUTPUT directory will
                    # be empty (see above) so no need to save.
                    if attempt > 0:
                        saved_output_directory = os.path.join(test.output_directory, str(attempt))
                        logger.info("moving contents of '%s' to '%s'",
                                    test.output_directory, saved_output_directory)
                        args.dry_run or os.makedirs(saved_output_directory, exist_ok=True)
                        for name in os.listdir(test.output_directory):
                            if os.path.isfile(src):
                                src = os.path.join(test.output_directory, name)
                                dst = os.path.join(saved_output_directory, name)
                                logger.debug("moving '%s' to '%s'", src, dst)
                                args.dry_run or os.replace(src, dst)

                # Start a debug log in the OUTPUT directory; include
                # timing for this specific test attempt.
                with logutil.TIMER, logutil.Debug(logger, os.path.join(test.output_directory, "debug.log")):
                    logger.info("****** test %s attempt %d of %d started at %s ******",
                                test.name, attempt+1, args.attempts, datetime.now())

                    if saved_output_directory:
                        logger.info("contents of '%s' moved to '%s'",
                                    test.output_directory, saved_output_directory)
                    saved_output_directory = None

                    ending = "undefined"
                    try:
                        if not args.dry_run:
                            runner.run_test(test, max_workers=args.workers)
                        ending = "finished"
                        result = post.mortem(test, args, update=(not args.dry_run))
                        if not args.dry_run:
                            # Store enough to fool the script
                            # pluto-testlist-scan.sh.
                            logger.info("storing result in '%s'", test.result_file)
                            with open(test.result_file, "w") as f:
                                f.write('"result": "%s"\n' % result)
                    except pexpect.TIMEOUT as e:
                        ending = "timeout"
                        logger.exception("**** test %s timed out ****", test.name)
                        result = post.mortem(test, args, update=(not args.dry_run))
                    # Since the OUTPUT directory exists, all paths to
                    # here should have a non-null RESULT.
                    test_stats.add("attempts(%s:%s)" % (ending, result), test)
                    if result.errors:
                        logger.info("****** test %s %s %s ******", test.name, result, result.errors)
                    else:
                        logger.info("****** test %s %s ******", test.name, result)
                    if result.passed:
                        break

            # Above will have set RESULT.  During a control-c or crash
            # the below will not be executed.

            test_stats.add("tests(%s)" % result, test)
            result_stats.add_result(result, old_result)

            test_stats.log_summary(logger.info, header="updated stats:",
                                   prefix="    ")
            result_stats.log_summary(logger.info, header="updated results:",
                                     prefix="    ")

    except KeyboardInterrupt:
        logger.exception("**** test %s interrupted ****", test.name)
        return 1

    level = args.verbose and logger.info or logger.debug
    test_stats.log_details(level, header="stat details:", prefix="  ")
    result_stats.log_details(logger.info, header="result details:", prefix="  ")

    test_stats.log_summary(logger.info, header="stat summary:", prefix="  ")
    result_stats.log_summary(logger.info, header="result summary:", prefix="  ")

    end_time = datetime.now()
    logger.info("run finished at %s after %s", end_time, end_time - start_time)

    return 0
Beispiel #7
0
def main():

    # If SIGUSR1, backtrace all threads; hopefully this is early
    # enough.
    faulthandler.register(signal.SIGUSR1)

    parser = argparse.ArgumentParser(description="Run tests",
                                     epilog="SIGUSR1 will dump all thread stacks")

    parser.add_argument("--verbose", "-v", action="count", default=0)

    parser.add_argument("directories", metavar="DIRECTORY", nargs="+",
                        help="a testsuite directory, a TESTLIST file, or a list of test directories")
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    logutil.add_arguments(parser)
    skip.add_arguments(parser)
    ignore.add_arguments(parser)
    publish.add_arguments(parser)

    # These three calls go together
    args = parser.parse_args()
    logutil.config(args, sys.stdout)
    logger = logutil.getLogger("kvmrunner")

    logger.info("Options:")
    logger.info("  directories: %s", args.directories)
    logger.info("  verbose: %s", args.verbose)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    logutil.log_arguments(logger, args)
    skip.log_arguments(logger, args)
    ignore.log_arguments(logger, args)
    publish.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger, args.directories, args,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directories)
        return 1

    test_stats = stats.Tests()
    result_stats = stats.Results()

    try:
        exit_code = 0
        logger.info("run started at %s", timing.START_TIME)
        runner.run_tests(logger, args, tests, test_stats, result_stats)
    except KeyboardInterrupt:
        logger.exception("**** interrupted ****")
        exit_code = 1

    test_stats.log_details(args.verbose and logger.info or logger.debug,
                           header="final stat details:", prefix="  ")
    result_stats.log_details(logger.info, header="final test details:", prefix="  ")

    test_stats.log_summary(logger.info, header="final test stats:", prefix="  ")
    result_stats.log_summary(logger.info, header="final test results:", prefix="  ")

    stop_time = datetime.now()
    logger.info("run finished at %s after %s", stop_time, stop_time - timing.START_TIME)

    return exit_code
Beispiel #8
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    # This argument's behaviour is overloaded; the shorter word "try"
    # is a python word.
    parser.add_argument("--retry", type=int, metavar="COUNT",
                        help=("number of times a test should be attempted before giving up"
                              " (tests are categorised as not-started (no OUTPUT directory), incomplete, failed, passed)"
                              "; a negative %(metavar)s selects all tests"
                              "; a zero %(metavar)s selects not-started tests"
                              "; a positive %(metavar)s selects not-started, incomplete and failing tests"
                              "; default is to select not-started tests"))
    parser.add_argument("--dry-run", "-n", action="store_true")
    parser.add_argument("--verbose", "-v", action="count", default=0)
    parser.add_argument("directories", metavar="DIRECTORY", nargs="+",
                        help=("Either a testsuite directory or"
                              " a list of test directories"))
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    post.add_arguments(parser)
    logutil.add_arguments(parser)

    args = parser.parse_args()
    logutil.config(args)

    logger = logutil.getLogger("kvmrunner")
    logger.info("Options:")
    logger.info("  retry: %s", args.retry or "0 (default)")
    logger.info("  dry-run: %s", args.dry_run)
    logger.info("  directories: %s", args.directories)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    post.log_arguments(logger, args)
    logutil.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger, args.directories,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directory)
        return 1

    # A list of test directories was specified (i.e, not a testsuite),
    # then force the tests to run.
    if isinstance(tests, list) and args.retry is None:
        args.retry = 1;
        logger.info("Explicit directory list; forcing --retry=%d (retry failed tests)", args.retry)

    # Use a default dict so no need to worry about initializing values
    # to zero.
    stats = Stats()
    results = Results()
    start_time = time.localtime()

    try:
        logger.info("run started at %s", datetime.now())

        for test in tests:
            stats.add("total", test)

            ignore = testsuite.ignore(test, args)
            if ignore:
                stats.add("ignored", test)
                # No need to log all the ignored tests when an
                # explicit sub-set of tests is being run.  For
                # instance, when running just one test.
                if not args.test_name:
                    logger.info("*** %s: ignore (%s)", test.name, ignore)
                continue

            # Implement "--retry" as described above: if retry is -ve,
            # the test is always run; if there's no result, the test
            # is always run; skip passed tests; else things get a
            # little wierd.
            retry = args.retry or 0
            if retry >= 0:
                result = post.mortem(test, args)
                if result:
                    if result.passed:
                        logger.info("*** %s: passed", test.name)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
                    if retry == 0:
                        logger.info("*** %s: %s (delete '%s' to re-test)", test.name,
                                    result.value, test.output_directory)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
            stats.add("tests", test)

            debugfile = None
            result = None

            # At least one iteration; above will have filtered out
            # skips and ignores
            runs = max(abs(retry), 1)
            for run in range(runs):
                stats.add("runs", test)

                # Create an output directory.  If there's already an
                # existing OUTPUT directory rename it to OUTPUT...
                # Need to do this before the OUTPUT/debug.log is
                # started as otherwise it too would get moved away.
                saved_output_directory = None
                if not args.dry_run:
                    try:
                        os.mkdir(test.output_directory)
                    except FileExistsError:
                        stats.add("reruns", test)
                        # Include the time this test run started in
                        # the suffix - that way all saved results can
                        # be matched using a wild card.  Include the
                        # time the directory was last modified in the
                        # suffix - it makes a good approximation as to
                        # when the previous test run finished.
                        stat = os.stat(test.output_directory)
                        mtime = time.localtime(os.stat(test.output_directory).st_mtime)
                        saved_output_directory = (test.output_directory
                                                + time.strftime(".%Y%m%d%H%M", start_time)
                                                + time.strftime(".%H%M%S", mtime))
                        logger.debug("renaming '%s' to '%s'",
                                     test.output_directory, saved_output_directory)
                        os.rename(test.output_directory, saved_output_directory)
                        # if the second attempt fails, let it crash
                        os.mkdir(test.output_directory)

                # Start a debug log in the OUTPUT directory; include
                # timing for this specific test run.
                with logutil.TIMER, logutil.Debug(logger, os.path.join(test.output_directory, "debug.log")):
                    logger.info("****** test %s attempt %d of %d started at %s ******",
                                test.name, run+1, runs, datetime.now())
                    # Add a log message about any saved output
                    # directory to the per-test-run debug log.  It
                    # just looks better.
                    if saved_output_directory:
                        logger.info("existing OUTPUT saved in '%s'",
                                    saved_output_directory)
                    ending = "undefined"
                    try:
                        if not args.dry_run:
                            runner.run_test(test, max_workers=args.workers)
                        ending = "finished"
                        result = post.mortem(test, args, update=(not args.dry_run))
                        if not args.dry_run:
                            # Store enough to fool the script
                            # pluto-testlist-scan.sh.
                            logger.info("storing result in '%s'", test.result_file)
                            with open(test.result_file, "w") as f:
                                f.write('"result": "')
                                f.write(result.value)
                                f.write('"')
                                f.write("\n")
                    except pexpect.TIMEOUT as e:
                        ending = "timeout"
                        logger.exception("**** test %s timed out ****", test.name)
                        result = post.mortem(test, args, update=(not args.dry_run))
                    # Since the OUTPUT directory exists, all paths to
                    # here should have a non-null RESULT.
                    stats.add("runs(%s:%s)" % (ending, result.value), test)
                    logger.info("****** test %s %s ******", test.name, result)
                    if result.passed:
                        break

            # Above will have set RESULT (don't reach here during
            # cntrl-c or crash).
            results.add(result)
            stats.add("tests(%s)" % result.value, test)

    except KeyboardInterrupt:
        logger.exception("**** test %s interrupted ****", test.name)
        return 1

    finally:
        logger.info("run finished at %s", datetime.now())

        level = args.verbose and logutil.INFO or logutil.DEBUG
        logger.log(level, "stat details:")
        stats.log_details(logger, level=level, prefix="  ")

        logger.info("result details:")
        results.log_details(logger, level=logutil.INFO, prefix="  ")

        logger.info("stat summary:")
        stats.log_summary(logger, level=logutil.INFO, prefix="  ")
        logger.info("result summary:")
        results.log_summary(logger, level=logutil.INFO, prefix="  ")

    return 0
Beispiel #9
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    # This argument's behaviour is overloaded; the shorter word "try"
    # is a python word.
    parser.add_argument("--retry", type=int, metavar="COUNT",
                        help="number of times a test should be attempted before giving up (tests are categorised as not-started (no OUTPUT directory), incomplete, failed, passed); a negative %(metavar)s selects all tests; a zero %(metavar)s selects not-started tests; a positive %(metavar)s selects not-started, incomplete and failing tests; default is to select not-started tests")
    parser.add_argument("--dry-run", "-n", action="store_true")
    parser.add_argument("--verbose", "-v", action="count", default=0)
    parser.add_argument("--output-directory", default=None, metavar="DIRECTORY",
                        help="save test results as %(metavar)s/<test> instead of <test>/OUTPUT")
    parser.add_argument("directories", metavar="DIRECTORY", nargs="+",
                        help="either a testsuite directory or a list of test directories")
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    post.add_arguments(parser)
    logutil.add_arguments(parser)

    args = parser.parse_args()
    logutil.config(args)

    logger = logutil.getLogger("kvmrunner")
    logger.info("Options:")
    logger.info("  retry: %s", args.retry or "0 (default)")
    logger.info("  dry-run: %s", args.dry_run)
    logger.info("  output-directory: %s", args.output_directory or "<testsuite>/<test>/OUTPUT (default)")
    logger.info("  directories: %s", args.directories)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    post.log_arguments(logger, args)
    logutil.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger, args.directories, args,
                                              testsuite_output_directory=args.output_directory,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directories)
        return 1

    # A list of test directories was specified (i.e, not a testsuite),
    # then force the tests to run.
    if isinstance(tests, list) and args.retry is None:
        args.retry = 1;
        logger.info("Explicit directory list; forcing --retry=%d (retry failed tests)", args.retry)

    # Use a default dict so no need to worry about initializing values
    # to zero.
    stats = Stats()
    results = Results()
    start_time = time.localtime()

    try:
        logger.info("run started at %s", datetime.now())

        test_count = 0
        for test in tests:
            stats.add("total", test)
            test_count += 1
            # Would the number of tests to be [re]run be better?
            test_prefix = "****** %s (test %d of %d)" % (test.name, test_count, len(tests))

            ignore = testsuite.ignore(test, args)
            if ignore:
                stats.add("ignored", test)
                # No need to log all the ignored tests when an
                # explicit sub-set of tests is being run.  For
                # instance, when running just one test.
                if not args.test_name:
                    logger.info("%s: ignore (%s)", test_prefix, ignore)
                continue

            # Implement "--retry" as described above: if retry is -ve,
            # the test is always run; if there's no result, the test
            # is always run; skip passed tests; else things get a
            # little wierd.
            retry = args.retry or 0
            if retry >= 0:
                result = post.mortem(test, args)
                if result:
                    if result.passed:
                        logger.info("%s: passed", test_prefix)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
                    if retry == 0:
                        logger.info("%s: %s (delete '%s' to re-test)", test_prefix,
                                    result, test.output_directory)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
                    stats.add("retry", test)

            logger.info("%s: starting ...", test_prefix)
            stats.add("tests", test)

            debugfile = None
            result = None

            # At least one iteration; above will have filtered out
            # skips and ignores
            attempts = max(abs(retry), 1)
            for attempt in range(attempts):
                stats.add("attempts", test)

                # On first attempt (attempt == 0), empty the
                # <test>/OUTPUT/ directory of all contents.  On
                # subsequent attempts, move the files from the
                # previous attempt to <test>/OUTPUT/<attempt>/.
                #
                # XXX: Don't just delete the OUTPUT/ directory as
                # this, for a short period, changes the status of the
                # test to never-run.
                #
                # XXX: During boot, swan-transmogrify runs "chcon -R
                # testing/pluto".  Of course this means that each time
                # a test is added and/or a test is run (adding files
                # under <test>/OUTPUT), the boot process (and
                # consequently the time taken to run a test) keeps
                # increasing.
                #
                # Mitigate this slightly by emptying <test>/OUTPUT
                # before starting any test attempts.  It's assumed
                # that the previous test run was already captured
                # above with save-directory.

                if not args.dry_run:
                    try:
                        os.mkdir(test.output_directory)
                    except FileExistsError:
                        saved_output_directory = os.path.join(test.output_directory, str(attempt))
                        logger.info("emptying directory '%s'", test.output_directory)
                        for name in os.listdir(test.output_directory):
                            src = os.path.join(test.output_directory, name)
                            if attempt == 0:
                                logger.debug("  remove '%s'", src)
                                if os.path.isfile(src):
                                    os.remove(src)
                                else:
                                    shutil.rmtree(src)
                            elif os.path.isfile(src):
                                dst = os.path.join(saved_output_directory, name)
                                logger.debug("  move '%s' to '%s'", src, dst)
                                os.makedirs(saved_output_directory, exist_ok=True)
                                os.rename(src, dst)

                # Start a debug log in the OUTPUT directory; include
                # timing for this specific test attempt.
                with logutil.TIMER, logutil.Debug(logger, os.path.join(test.output_directory, "debug.log")):
                    logger.info("****** test %s attempt %d of %d started at %s ******",
                                test.name, attempt+1, attempts, datetime.now())

                    ending = "undefined"
                    try:
                        if not args.dry_run:
                            runner.run_test(test, max_workers=args.workers)
                        ending = "finished"
                        result = post.mortem(test, args, update=(not args.dry_run))
                        if not args.dry_run:
                            # Store enough to fool the script
                            # pluto-testlist-scan.sh.
                            logger.info("storing result in '%s'", test.result_file)
                            with open(test.result_file, "w") as f:
                                f.write('"result": "%s"\n' % result)
                    except pexpect.TIMEOUT as e:
                        ending = "timeout"
                        logger.exception("**** test %s timed out ****", test.name)
                        result = post.mortem(test, args, update=(not args.dry_run))
                    # Since the OUTPUT directory exists, all paths to
                    # here should have a non-null RESULT.
                    stats.add("attempts(%s:%s)" % (ending, result), test)
                    logger.info("****** test %s %s ******", test.name, result)
                    if result.passed:
                        break

            # Above will have set RESULT (don't reach here during
            # cntrl-c or crash).
            results.add(result)
            stats.add("tests(%s)" % result, test)

    except KeyboardInterrupt:
        logger.exception("**** test %s interrupted ****", test.name)
        return 1

    finally:
        logger.info("run finished at %s", datetime.now())

        level = args.verbose and logutil.INFO or logutil.DEBUG
        logger.log(level, "stat details:")
        stats.log_details(logger, level=level, prefix="  ")

        logger.info("result details:")
        results.log_details(logger, level=logutil.INFO, prefix="  ")

        logger.info("stat summary:")
        stats.log_summary(logger, level=logutil.INFO, prefix="  ")
        logger.info("result summary:")
        results.log_summary(logger, level=logutil.INFO, prefix="  ")

    return 0
Beispiel #10
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    # This argument's behaviour is overloaded; the shorter word "try"
    # is a python word.
    parser.add_argument(
        "--retry",
        type=int,
        metavar="COUNT",
        help=
        "number of times a test should be attempted before giving up (tests are categorised as not-started (no OUTPUT directory), incomplete, failed, passed); a negative %(metavar)s selects all tests; a zero %(metavar)s selects not-started tests; a positive %(metavar)s selects not-started, incomplete and failing tests; default is to select not-started tests"
    )
    parser.add_argument("--dry-run", "-n", action="store_true")
    parser.add_argument("--verbose", "-v", action="count", default=0)
    parser.add_argument(
        "--output-directory",
        default=None,
        metavar="DIRECTORY",
        help="save test results as %(metavar)s/<test> instead of <test>/OUTPUT"
    )
    parser.add_argument(
        "directories",
        metavar="DIRECTORY",
        nargs="+",
        help="either a testsuite directory or a list of test directories")
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    post.add_arguments(parser)
    logutil.add_arguments(parser)

    args = parser.parse_args()
    logutil.config(args)

    logger = logutil.getLogger("kvmrunner")
    logger.info("Options:")
    logger.info("  retry: %s", args.retry or "0 (default)")
    logger.info("  dry-run: %s", args.dry_run)
    logger.info("  output-directory: %s", args.output_directory
                or "<testsuite>/<test>/OUTPUT (default)")
    logger.info("  directories: %s", args.directories)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    post.log_arguments(logger, args)
    logutil.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(
        logger,
        args.directories,
        args,
        testsuite_output_directory=args.output_directory,
        log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s",
                     args.directories)
        return 1

    # A list of test directories was specified (i.e, not a testsuite),
    # then force the tests to run.
    if isinstance(tests, list) and args.retry is None:
        args.retry = 1
        logger.info(
            "Explicit directory list; forcing --retry=%d (retry failed tests)",
            args.retry)

    # Use a default dict so no need to worry about initializing values
    # to zero.
    stats = Stats()
    results = Results()
    start_time = time.localtime()

    try:
        logger.info("run started at %s", datetime.now())

        test_count = 0
        for test in tests:
            stats.add("total", test)
            test_count += 1
            # Would the number of tests to be [re]run be better?
            test_prefix = "****** %s (test %d of %d)" % (test.name, test_count,
                                                         len(tests))

            ignore = testsuite.ignore(test, args)
            if ignore:
                stats.add("ignored", test)
                # No need to log all the ignored tests when an
                # explicit sub-set of tests is being run.  For
                # instance, when running just one test.
                if not args.test_name:
                    logger.info("%s: ignore (%s)", test_prefix, ignore)
                continue

            # Implement "--retry" as described above: if retry is -ve,
            # the test is always run; if there's no result, the test
            # is always run; skip passed tests; else things get a
            # little wierd.
            retry = args.retry or 0
            if retry >= 0:
                result = post.mortem(test, args)
                if result:
                    if result.passed:
                        logger.info("%s: passed", test_prefix)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
                    if retry == 0:
                        logger.info("%s: %s (delete '%s' to re-test)",
                                    test_prefix, result, test.output_directory)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
                    stats.add("retry", test)

            logger.info("%s: starting ...", test_prefix)
            stats.add("tests", test)

            debugfile = None
            result = None

            # At least one iteration; above will have filtered out
            # skips and ignores
            attempts = max(abs(retry), 1)
            for attempt in range(attempts):
                stats.add("attempts", test)

                # Create an output directory.  If there's already an
                # existing OUTPUT directory copy its contents to:
                #
                #     OUTPUT/YYYYMMDDHHMMSS.ATTEMPT
                #
                # so, when re-running, earlier attempts are saved.  Do
                # this before the OUTPUT/debug.log is started so that
                # each test attempt has its own log, and otherwise, it
                # too would be moved away.
                saved_output_directory = None
                saved_output = []
                if not args.dry_run:
                    try:
                        os.mkdir(test.output_directory)
                    except FileExistsError:
                        # Include the time this test run started in
                        # the suffix - that way all saved results can
                        # be matched using a wild card.
                        saved_output_directory = os.path.join(
                            test.output_directory, "%s.%d" % (time.strftime(
                                "%Y%m%d%H%M%S", start_time), attempt))
                        logger.debug("moving existing OUTPUT to '%s'",
                                     saved_output_directory)
                        for name in os.listdir(test.output_directory):
                            src = os.path.join(test.output_directory, name)
                            dst = os.path.join(saved_output_directory, name)
                            if os.path.isfile(src):
                                os.makedirs(saved_output_directory,
                                            exist_ok=True)
                                os.rename(src, dst)
                                saved_output.append(name)
                                logger.debug("  moved '%s' to '%s'", src, dst)

                # Start a debug log in the OUTPUT directory; include
                # timing for this specific test attempt.
                with logutil.TIMER, logutil.Debug(
                        logger, os.path.join(test.output_directory,
                                             "debug.log")):
                    logger.info(
                        "****** test %s attempt %d of %d started at %s ******",
                        test.name, attempt + 1, attempts, datetime.now())

                    # Add a log message about any saved output
                    # directory to the per-test-attempt debug log.  It
                    # just looks better.
                    if saved_output:
                        logger.info("saved existing '%s' in '%s'",
                                    saved_output, saved_output_directory)

                    ending = "undefined"
                    try:
                        if not args.dry_run:
                            runner.run_test(test, max_workers=args.workers)
                        ending = "finished"
                        result = post.mortem(test,
                                             args,
                                             update=(not args.dry_run))
                        if not args.dry_run:
                            # Store enough to fool the script
                            # pluto-testlist-scan.sh.
                            logger.info("storing result in '%s'",
                                        test.result_file)
                            with open(test.result_file, "w") as f:
                                f.write('"result": "%s"\n' % result)
                    except pexpect.TIMEOUT as e:
                        ending = "timeout"
                        logger.exception("**** test %s timed out ****",
                                         test.name)
                        result = post.mortem(test,
                                             args,
                                             update=(not args.dry_run))
                    # Since the OUTPUT directory exists, all paths to
                    # here should have a non-null RESULT.
                    stats.add("attempts(%s:%s)" % (ending, result), test)
                    logger.info("****** test %s %s ******", test.name, result)
                    if result.passed:
                        break

            # Above will have set RESULT (don't reach here during
            # cntrl-c or crash).
            results.add(result)
            stats.add("tests(%s)" % result, test)

    except KeyboardInterrupt:
        logger.exception("**** test %s interrupted ****", test.name)
        return 1

    finally:
        logger.info("run finished at %s", datetime.now())

        level = args.verbose and logutil.INFO or logutil.DEBUG
        logger.log(level, "stat details:")
        stats.log_details(logger, level=level, prefix="  ")

        logger.info("result details:")
        results.log_details(logger, level=logutil.INFO, prefix="  ")

        logger.info("stat summary:")
        stats.log_summary(logger, level=logutil.INFO, prefix="  ")
        logger.info("result summary:")
        results.log_summary(logger, level=logutil.INFO, prefix="  ")

    return 0
Beispiel #11
0
def main():
    parser = argparse.ArgumentParser(description="Run tests")

    # This argument's behaviour is overloaded; the shorter word "try"
    # is a python word.
    parser.add_argument("--retry", type=int, metavar="COUNT",
                        help="number of times a test should be attempted before giving up (tests are categorised as not-started (no OUTPUT directory), incomplete, failed, passed); a negative %(metavar)s selects all tests; a zero %(metavar)s selects not-started tests; a positive %(metavar)s selects not-started, incomplete and failing tests; default is to select not-started tests")
    parser.add_argument("--dry-run", "-n", action="store_true")
    parser.add_argument("--verbose", "-v", action="count", default=0)
    parser.add_argument("--output-directory", default=None, metavar="DIRECTORY",
                        help="save test results as %(metavar)s/<test> instead of <test>/OUTPUT")
    parser.add_argument("directories", metavar="DIRECTORY", nargs="+",
                        help="either a testsuite directory or a list of test directories")
    testsuite.add_arguments(parser)
    runner.add_arguments(parser)
    post.add_arguments(parser)
    logutil.add_arguments(parser)

    args = parser.parse_args()
    logutil.config(args)

    logger = logutil.getLogger("kvmrunner")
    logger.info("Options:")
    logger.info("  retry: %s", args.retry or "0 (default)")
    logger.info("  dry-run: %s", args.dry_run)
    logger.info("  output-directory: %s", args.output_directory or "<testsuite>/<test>/OUTPUT (default)")
    logger.info("  directories: %s", args.directories)
    testsuite.log_arguments(logger, args)
    runner.log_arguments(logger, args)
    post.log_arguments(logger, args)
    logutil.log_arguments(logger, args)

    tests = testsuite.load_testsuite_or_tests(logger, args.directories, args,
                                              testsuite_output_directory=args.output_directory,
                                              log_level=logutil.INFO)
    if not tests:
        logger.error("test or testsuite directory invalid: %s", args.directories)
        return 1

    # A list of test directories was specified (i.e, not a testsuite),
    # then force the tests to run.
    if isinstance(tests, list) and args.retry is None:
        args.retry = 1;
        logger.info("Explicit directory list; forcing --retry=%d (retry failed tests)", args.retry)

    # Use a default dict so no need to worry about initializing values
    # to zero.
    stats = Stats()
    results = Results()
    start_time = time.localtime()

    try:
        logger.info("run started at %s", datetime.now())

        test_count = 0
        for test in tests:
            stats.add("total", test)
            test_count += 1
            # Would the number of tests to be [re]run be better?
            test_prefix = "****** %s (test %d of %d)" % (test.name, test_count, len(tests))

            ignore = testsuite.ignore(test, args)
            if ignore:
                stats.add("ignored", test)
                # No need to log all the ignored tests when an
                # explicit sub-set of tests is being run.  For
                # instance, when running just one test.
                if not args.test_name:
                    logger.info("%s: ignore (%s)", test_prefix, ignore)
                continue

            # Implement "--retry" as described above: if retry is -ve,
            # the test is always run; if there's no result, the test
            # is always run; skip passed tests; else things get a
            # little wierd.
            retry = args.retry or 0
            if retry >= 0:
                result = post.mortem(test, args)
                if result:
                    if result.passed:
                        logger.info("%s: passed", test_prefix)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
                    if retry == 0:
                        logger.info("%s: %s (delete '%s' to re-test)", test_prefix,
                                    result, test.output_directory)
                        stats.add("skipped", test)
                        results.add(result)
                        continue
                    stats.add("retry", test)

            logger.info("%s: starting ...", test_prefix)
            stats.add("tests", test)

            debugfile = None
            result = None

            # At least one iteration; above will have filtered out
            # skips and ignores
            attempts = max(abs(retry), 1)
            for attempt in range(attempts):
                stats.add("attempts", test)

                # Create an output directory.  If there's already an
                # existing OUTPUT directory copy its contents to:
                #
                #     OUTPUT/YYYYMMDDHHMMSS.ATTEMPT
                #
                # so, when re-running, earlier attempts are saved.  Do
                # this before the OUTPUT/debug.log is started so that
                # each test attempt has its own log, and otherwise, it
                # too would be moved away.
                saved_output_directory = None
                saved_output = []
                if not args.dry_run:
                    try:
                        os.mkdir(test.output_directory)
                    except FileExistsError:
                        # Include the time this test run started in
                        # the suffix - that way all saved results can
                        # be matched using a wild card.
                        saved_output_directory = os.path.join(test.output_directory,
                                                              "%s.%d" % (time.strftime("%Y%m%d%H%M%S", start_time), attempt))
                        logger.debug("moving existing OUTPUT to '%s'", saved_output_directory)
                        for name in os.listdir(test.output_directory):
                            src = os.path.join(test.output_directory, name)
                            dst = os.path.join(saved_output_directory, name)
                            if os.path.isfile(src):
                                os.makedirs(saved_output_directory, exist_ok=True)
                                os.rename(src, dst)
                                saved_output.append(name)
                                logger.debug("  moved '%s' to '%s'", src, dst)

                # Start a debug log in the OUTPUT directory; include
                # timing for this specific test attempt.
                with logutil.TIMER, logutil.Debug(logger, os.path.join(test.output_directory, "debug.log")):
                    logger.info("****** test %s attempt %d of %d started at %s ******",
                                test.name, attempt+1, attempts, datetime.now())

                    # Add a log message about any saved output
                    # directory to the per-test-attempt debug log.  It
                    # just looks better.
                    if saved_output:
                        logger.info("saved existing '%s' in '%s'", saved_output, saved_output_directory)

                    ending = "undefined"
                    try:
                        if not args.dry_run:
                            runner.run_test(test, max_workers=args.workers)
                        ending = "finished"
                        result = post.mortem(test, args, update=(not args.dry_run))
                        if not args.dry_run:
                            # Store enough to fool the script
                            # pluto-testlist-scan.sh.
                            logger.info("storing result in '%s'", test.result_file)
                            with open(test.result_file, "w") as f:
                                f.write('"result": "%s"\n' % result)
                    except pexpect.TIMEOUT as e:
                        ending = "timeout"
                        logger.exception("**** test %s timed out ****", test.name)
                        result = post.mortem(test, args, update=(not args.dry_run))
                    # Since the OUTPUT directory exists, all paths to
                    # here should have a non-null RESULT.
                    stats.add("attempts(%s:%s)" % (ending, result), test)
                    logger.info("****** test %s %s ******", test.name, result)
                    if result.passed:
                        break

            # Above will have set RESULT (don't reach here during
            # cntrl-c or crash).
            results.add(result)
            stats.add("tests(%s)" % result, test)

    except KeyboardInterrupt:
        logger.exception("**** test %s interrupted ****", test.name)
        return 1

    finally:
        logger.info("run finished at %s", datetime.now())

        level = args.verbose and logutil.INFO or logutil.DEBUG
        logger.log(level, "stat details:")
        stats.log_details(logger, level=level, prefix="  ")

        logger.info("result details:")
        results.log_details(logger, level=logutil.INFO, prefix="  ")

        logger.info("stat summary:")
        stats.log_summary(logger, level=logutil.INFO, prefix="  ")
        logger.info("result summary:")
        results.log_summary(logger, level=logutil.INFO, prefix="  ")

    return 0