diff options
-rw-r--r-- | buildscripts/patch_builds/task_generation.py | 1 | ||||
-rw-r--r-- | buildscripts/resmoke_tests_runtime_validate.py | 123 | ||||
-rw-r--r-- | buildscripts/resmokelib/testing/report.py | 13 | ||||
-rw-r--r-- | buildscripts/tests/patch_builds/test_task_generation.py | 21 | ||||
-rw-r--r-- | etc/evergreen.yml | 11 | ||||
-rw-r--r-- | evergreen/resmoke_tests_runtime_validate.sh | 15 |
6 files changed, 169 insertions, 15 deletions
diff --git a/buildscripts/patch_builds/task_generation.py b/buildscripts/patch_builds/task_generation.py index 7eb0e3f5bf2..fa2cc0cc5c3 100644 --- a/buildscripts/patch_builds/task_generation.py +++ b/buildscripts/patch_builds/task_generation.py @@ -49,6 +49,7 @@ def resmoke_commands(run_tests_fn_name: str, run_tests_vars: Dict[str, Any], FunctionCall(CONFIGURE_EVG_CREDENTIALS), FunctionCall(DO_MULTIVERSION_SETUP) if require_multiversion_setup else None, FunctionCall(run_tests_fn_name, run_tests_vars), + FunctionCall("validate resmoke tests runtime"), ] return [cmd for cmd in commands if cmd] diff --git a/buildscripts/resmoke_tests_runtime_validate.py b/buildscripts/resmoke_tests_runtime_validate.py new file mode 100644 index 00000000000..cffcbf48e9d --- /dev/null +++ b/buildscripts/resmoke_tests_runtime_validate.py @@ -0,0 +1,123 @@ +#!/usr/bin/env python3 +"""Utility to validate resmoke tests runtime.""" +import json +import sys +from collections import namedtuple +from datetime import datetime, timedelta +from statistics import mean +from typing import Dict, List + +import click +import structlog + +from buildscripts.resmokelib.testing.report import TestInfo, TestReport +from buildscripts.resmokelib.utils import get_task_name_without_suffix +from buildscripts.util.cmdutils import enable_logging +from evergreen import RetryingEvergreenApi, TestStats + +LOGGER = structlog.get_logger("buildscripts.resmoke_tests_runtime_validate") + +LOOK_BACK_NUM_DAYS = 20 +BURN_IN_PREFIX = "burn_in:" + +HISTORIC_MAX_MULTIPLIER = 1.5 +IGNORE_LESS_THAN_SECS = 15 + +_TestData = namedtuple("TestData", ["test_file", "duration"]) + + +def parse_resmoke_report(report_file: str) -> List[TestInfo]: + """Get js tests info from resmoke report json.""" + with open(report_file, "r") as fh: + report_data = json.load(fh) + test_report = TestReport.from_dict(report_data) + return [test_info for test_info in test_report.test_infos if "jstests" in test_info.test_file] + + +def get_historic_stats(evg_api_config: str, project_id: str, test_files: List[str], task_name: str, + build_variant: str) -> List[TestStats]: + """Get historic test stats.""" + evg_api = RetryingEvergreenApi.get_api(config_file=evg_api_config) + before_date = datetime.today() + after_date = before_date - timedelta(days=LOOK_BACK_NUM_DAYS) + base_task_name = get_task_name_without_suffix(task_name, build_variant).replace( + BURN_IN_PREFIX, "") + return evg_api.test_stats_by_project(project_id=project_id, after_date=after_date, + before_date=before_date, tests=test_files, + tasks=[base_task_name], variants=[build_variant]) + + +def make_stats_map(stats: List[_TestData]) -> Dict[str, List[float]]: + """Make test stats map.""" + stats_map = {} + + for stat in stats: + if stat.test_file in stats_map: + stats_map[stat.test_file].append(stat.duration) + else: + stats_map[stat.test_file] = [stat.duration] + + return stats_map + + +@click.command() +@click.option("--resmoke-report-file", type=str, required=True, + help="Location of resmoke's report JSON file.") +@click.option("--evg-api-config", type=str, required=True, + help="Location of evergreen api configuration.") +@click.option("--project-id", type=str, required=True, help="Evergreen project id.") +@click.option("--build-variant", type=str, required=True, help="Evergreen build variant name.") +@click.option("--task-name", type=str, required=True, help="Evergreen task name.") +def main(resmoke_report_file: str, evg_api_config: str, project_id: str, build_variant: str, + task_name: str) -> None: + """Compare resmoke tests runtime with historic stats.""" + enable_logging(verbose=False) + + current_test_infos = parse_resmoke_report(resmoke_report_file) + current_stats_map = make_stats_map([ + _TestData(test_info.test_file, test_info.end_time - test_info.start_time) + for test_info in current_test_infos + ]) + + historic_stats = get_historic_stats(evg_api_config, project_id, list(current_stats_map.keys()), + task_name, build_variant) + historic_stats_map = make_stats_map([ + _TestData(test_stats.test_file, test_stats.avg_duration_pass) + for test_stats in historic_stats + ]) + + failed = False + + for test, stats in current_stats_map.items(): + current_mean = mean(stats) + if current_mean < IGNORE_LESS_THAN_SECS: + continue + + historic_test_stats = historic_stats_map.get(test) + if historic_test_stats: + historic_max = max(historic_test_stats) + target = historic_max * HISTORIC_MAX_MULTIPLIER + if current_mean > target: + LOGGER.error("Found long running test.", test_file=test, + current_mean_time=current_mean, maximum_expected_time=target, + historic_max_time=historic_max) + failed = True + + LOGGER.info("Done comparing resmoke tests runtime with historic stats.") + if failed: + percent = int((HISTORIC_MAX_MULTIPLIER - 1) * 100) + LOGGER.error( + f"The test failed due to its runtime taking {percent}% more than the recent max" + " and can negatively contribute to the future patch build experience." + " Consider checking if there is an unexpected regression.") + LOGGER.error("If the test is being intentionally expanded, please split it up into separate" + " JS files that run as separate tests.") + LOGGER.error( + "If you believe the test has inherently large variability, please consider writing" + " a new test instead of modifying this one.") + LOGGER.error("For any other questions or concerns, please reach out to #server-testing.") + sys.exit(1) + + +if __name__ == '__main__': + main() # pylint: disable=no-value-for-parameter diff --git a/buildscripts/resmokelib/testing/report.py b/buildscripts/resmokelib/testing/report.py index bb9198bd57c..51804f9d8f8 100644 --- a/buildscripts/resmokelib/testing/report.py +++ b/buildscripts/resmokelib/testing/report.py @@ -105,7 +105,7 @@ class TestReport(unittest.TestResult): # pylint: disable=too-many-instance-attr unittest.TestResult.startTest(self, test) - test_info = _TestInfo(test.id(), test.test_name, test.dynamic) + test_info = TestInfo(test.id(), test.test_name, test.dynamic) if _config.SPAWN_USING == "jasper": # The group id represents the group of logs this test belongs to in # cedar buildlogger. It must be sent to evergreen/cedar in order to @@ -322,14 +322,15 @@ class TestReport(unittest.TestResult): # pylint: disable=too-many-instance-attr Used when combining reports instances. """ - report = cls(logging.loggers.EXECUTOR_LOGGER, _config.SuiteOptions.ALL_INHERITED.resolve()) + report = cls(logging.loggers.ROOT_EXECUTOR_LOGGER, + _config.SuiteOptions.ALL_INHERITED.resolve()) for result in report_dict["results"]: # By convention, dynamic tests are named "<basename>:<hook name>". is_dynamic = ":" in result["test_file"] or ":" in result.get("display_test_name", "") test_file = result["test_file"] # Using test_file as the test id is ok here since the test id only needs to be unique # during suite execution. - test_info = _TestInfo(test_file, test_file, is_dynamic) + test_info = TestInfo(test_file, test_file, is_dynamic) test_info.display_test_name = result.get("display_test_name") test_info.group_id = result.get("group_id") test_info.url_endpoint = result.get("url") @@ -377,11 +378,11 @@ class TestReport(unittest.TestResult): # pylint: disable=too-many-instance-attr raise ValueError("Details for %s not found in the report" % (test.basename())) -class _TestInfo(object): # pylint: disable=too-many-instance-attributes +class TestInfo(object): # pylint: disable=too-many-instance-attributes """Holder for the test status and timing information.""" def __init__(self, test_id, test_file, dynamic): - """Initialize the _TestInfo instance.""" + """Initialize the TestInfo instance.""" self.test_id = test_id # If spawned using jasper, we need to set the display_test_name and the @@ -405,7 +406,7 @@ class _TestInfo(object): # pylint: disable=too-many-instance-attributes def test_order(test_name): """ - A key function used for sorting _TestInfo objects by recommended order of investigation. + A key function used for sorting TestInfo objects by recommended order of investigation. Investigate setup/teardown errors, then hooks, then test files. """ diff --git a/buildscripts/tests/patch_builds/test_task_generation.py b/buildscripts/tests/patch_builds/test_task_generation.py index defd2540b00..fea15ee9269 100644 --- a/buildscripts/tests/patch_builds/test_task_generation.py +++ b/buildscripts/tests/patch_builds/test_task_generation.py @@ -14,8 +14,9 @@ class TestResmokeCommand(unittest.TestCase): commands = under_test.resmoke_commands(run_tests, test_vars, timeout_info) - # 3 expected command = 1 for setup + 1 for evergreen credentials + 1 for running tests. - self.assertEqual(3, len(commands)) + # 4 expected command = 1 for setup + 1 for evergreen credentials + 1 for running tests + + # 1 for validate resmoke tests runtime. + self.assertEqual(4, len(commands)) def test_with_multiversion(self): run_tests = "run tests" @@ -25,8 +26,9 @@ class TestResmokeCommand(unittest.TestCase): commands = under_test.resmoke_commands(run_tests, test_vars, timeout_info, require_multiversion_setup=True) - # 4 expected command = 1 for setup + 1 for running tests + 3 for multiversion setup. - self.assertEqual(6, len(commands)) + # 7 expected command = 1 for setup + 1 for evergreen credentials + 3 for multiversion setup + + # 1 for running tests + 1 for validate resmoke tests runtime. + self.assertEqual(7, len(commands)) def test_with_timeout(self): run_tests = "run tests" @@ -35,8 +37,9 @@ class TestResmokeCommand(unittest.TestCase): commands = under_test.resmoke_commands(run_tests, test_vars, timeout_info) - # 4 expected command = 1 for setup + 1 for evergreen credentials + 1 for running tests + 1 for timeout. - self.assertEqual(4, len(commands)) + # 5 expected command = 1 for setup + 1 for evergreen credentials + 1 for running tests + + # 1 for timeout + 1 for validate resmoke tests runtime. + self.assertEqual(5, len(commands)) def test_with_everything(self): run_tests = "run tests" @@ -46,9 +49,9 @@ class TestResmokeCommand(unittest.TestCase): commands = under_test.resmoke_commands(run_tests, test_vars, timeout_info, require_multiversion_setup=True) - # 5 expected command = 1 for setup + 1 for running tests + 3 for multiversion setup + - # 1 for timeout. - self.assertEqual(7, len(commands)) + # 8 expected command = 1 for setup + 1 for evergreen credentials + 3 for multiversion setup + + # 1 for running tests + 1 for timeout + 1 for validate resmoke tests runtime. + self.assertEqual(8, len(commands)) class TestTimeoutInfo(unittest.TestCase): diff --git a/etc/evergreen.yml b/etc/evergreen.yml index 7e32967c849..eb487f27bab 100644 --- a/etc/evergreen.yml +++ b/etc/evergreen.yml @@ -1186,6 +1186,17 @@ functions: - "./src/evergreen/gen_tasks_activate.sh" # Used by generator + "validate resmoke tests runtime": + - *f_expansions_write + - *configure_evergreen_api_credentials + - command: subprocess.exec + type: test + params: + binary: bash + args: + - "./src/evergreen/resmoke_tests_runtime_validate.sh" + + # Used by generator "run generated tests": - *f_expansions_write - *retrieve_generated_test_configuration diff --git a/evergreen/resmoke_tests_runtime_validate.sh b/evergreen/resmoke_tests_runtime_validate.sh new file mode 100644 index 00000000000..1ccfc71c225 --- /dev/null +++ b/evergreen/resmoke_tests_runtime_validate.sh @@ -0,0 +1,15 @@ +DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" > /dev/null 2>&1 && pwd)" +. "$DIR/prelude.sh" + +cd src + +set -o verbose +set -o errexit + +activate_venv +$python buildscripts/resmoke_tests_runtime_validate.py \ + --resmoke-report-file ./report.json \ + --evg-api-config ./.evergreen.yml \ + --project-id ${project_id} \ + --build-variant ${build_variant} \ + --task-name ${task_name} |