diff options
Diffstat (limited to 'buildscripts/resmokelib/testing/hooks')
4 files changed, 168 insertions, 62 deletions
diff --git a/buildscripts/resmokelib/testing/hooks/aggregate_metrics_background.py b/buildscripts/resmokelib/testing/hooks/aggregate_metrics_background.py index d392c6ae0b8..c45f93192eb 100644 --- a/buildscripts/resmokelib/testing/hooks/aggregate_metrics_background.py +++ b/buildscripts/resmokelib/testing/hooks/aggregate_metrics_background.py @@ -4,70 +4,70 @@ This hook runs continuously, but the run_aggregate_metrics_background.js file it internally sleep for 1 second between runs. """ -import os.path +import random +import pymongo -from buildscripts.resmokelib import errors -from buildscripts.resmokelib.testing.hooks import jsfile -from buildscripts.resmokelib.testing.hooks.background_job import _BackgroundJob, _ContinuousDynamicJSTestCase +from buildscripts.resmokelib.testing.hooks.bghook import BGHook -class AggregateResourceConsumptionMetricsInBackground(jsfile.JSHook): - """A hook to run $operationMetrics stage in the background.""" - - IS_BACKGROUND = True - - def __init__(self, hook_logger, fixture, shell_options=None): - """Initialize AggregateResourceConsumptionMetricsInBackground.""" - description = "Run background $operationMetrics on all mongods while a test is running" - js_filename = os.path.join("jstests", "hooks", "run_aggregate_metrics_background.js") - jsfile.JSHook.__init__(self, hook_logger, fixture, js_filename, description, - shell_options=shell_options) - self._background_job = None +def verify_metrics(doc): + """Checks whether the output from $operatiomMetrics has the schema we expect.""" - def before_suite(self, test_report): - """Start the background thread.""" - self._background_job = _BackgroundJob("AggregateResourceConsumptionMetricsInBackground") - self.logger.info("Starting the background aggregate metrics thread.") - self._background_job.start() + top_level_fields = [ + "docBytesWritten", "docUnitsWritten", "idxEntryBytesWritten", "idxEntryUnitsWritten", + "totalUnitsWritten", "cpuNanos", "db", "primaryMetrics", "secondaryMetrics" + ] + read_fields = [ + "docBytesRead", "docUnitsRead", "idxEntryBytesRead", "idxEntryUnitsRead", "keysSorted", + "docUnitsReturned" + ] - def after_suite(self, test_report, teardown_flag=None): - """Signal the background aggregate metrics thread to exit, and wait until it does.""" - if self._background_job is None: - return + for key in top_level_fields: + assert key in doc, ("The metrics output is missing the property: " + key) - self.logger.info("Stopping the background aggregate metrics thread.") - self._background_job.stop() + primary_metrics = doc["primaryMetrics"] + for key in read_fields: + assert key in primary_metrics, ( + "The metrics output is missing the property: primaryMetrics." + key) - def before_test(self, test, test_report): - """Instruct the background aggregate metrics thread to run while 'test' is also running.""" - if self._background_job is None: - return + secondary_metrics = doc["secondaryMetrics"] + for key in read_fields: + assert key in secondary_metrics, ( + "The metrics output is missing the property: secondaryMetrics." + key) - hook_test_case = _ContinuousDynamicJSTestCase.create_before_test( - test.logger, test, self, self._js_filename, self._shell_options) - hook_test_case.configure(self.fixture) - self.logger.info("Resuming the background aggregate metrics thread.") - self._background_job.resume(hook_test_case, test_report) - - def after_test(self, test, test_report): # noqa: D205,D400 - """Instruct the background aggregate metrics thread to stop running now that 'test' has - finished running. - """ - if self._background_job is None: - return +class AggregateResourceConsumptionMetricsInBackground(BGHook): + """A hook to run $operationMetrics stage in the background.""" - self.logger.info("Pausing the background aggregate metrics thread.") - self._background_job.pause() + def __init__(self, hook_logger, fixture): + """Initialize AggregateResourceConsumptionMetricsInBackground.""" - if self._background_job.exc_info is not None: - if isinstance(self._background_job.exc_info[1], errors.TestFailure): - # If the mongo shell process running the JavaScript file exited with a non-zero - # return code, then we raise an errors.ServerFailure exception to cause resmoke.py's - # test execution to stop. - raise errors.ServerFailure(self._background_job.exc_info[1].args[0]) - else: - self.logger.error( - "Encountered an error inside the background aggregate metrics thread.", - exc_info=self._background_job.exc_info) - raise self._background_job.exc_info[1] + description = "Run background $operationMetrics on all mongods while a test is running" + super().__init__(hook_logger, fixture, description, tests_per_cycle=None, + loop_delay_ms=1000) + + def run_action(self): + """Collects $operationMetrics on all non-arbiter nodes in the fixture.""" + for node_info in self.fixture.get_node_info(): + conn = pymongo.MongoClient(port=node_info.port) + # Filter out arbiters. + if "arbiterOnly" in conn.admin.command({"isMaster": 1}): + self.logger.info( + "Skipping background aggregation against test node: %s because it is an " + + "arbiter and has no data.", node_info.full_name) + return + + # Clear the metrics about 10% of the time. + clear_metrics = random.random() < 0.1 + self.logger.info("Running $operationMetrics with {clearMetrics: %s} on host: %s", + clear_metrics, node_info.full_name) + with conn.admin.aggregate( + [{"$operationMetrics": {"clearMetrics": clear_metrics}}]) as cursor: + for doc in cursor: + try: + verify_metrics(doc) + except: + self.logger.info( + "caught exception while verifying that all expected fields are in the" + + " metrics output: ", doc) + raise diff --git a/buildscripts/resmokelib/testing/hooks/background_job.py b/buildscripts/resmokelib/testing/hooks/background_job.py index 92dbb5437a4..cd775aabd4a 100644 --- a/buildscripts/resmokelib/testing/hooks/background_job.py +++ b/buildscripts/resmokelib/testing/hooks/background_job.py @@ -3,6 +3,7 @@ import sys import threading +from buildscripts.resmokelib import errors from buildscripts.resmokelib.testing.hooks import jsfile diff --git a/buildscripts/resmokelib/testing/hooks/bghook.py b/buildscripts/resmokelib/testing/hooks/bghook.py index b61f37b4e2d..1b3fed3b104 100644 --- a/buildscripts/resmokelib/testing/hooks/bghook.py +++ b/buildscripts/resmokelib/testing/hooks/bghook.py @@ -13,11 +13,13 @@ class BGJob(threading.Thread): BGJob will call 'run_action' without any delay and expects the 'run_action' function to add some form of delay. """ - def __init__(self, hook): + def __init__(self, hook, loop_delay_ms=None): """Initialize the background job.""" threading.Thread.__init__(self, name=f"BGJob-{hook.__class__.__name__}") + self._loop_delay_ms = loop_delay_ms self.daemon = True self._hook = hook + self._interrupt_event = threading.Event() self.__is_alive = True self.err = None @@ -29,6 +31,14 @@ class BGJob(threading.Thread): try: self._hook.run_action() + if self._loop_delay_ms is not None: + # The configured loop delay asked us to wait before running the action again. Do + # that wait, but listen to see if we finish running the test or are killed in + # the meantime. + interrupted = self._interrupt_event.wait(self._loop_delay_ms / 1000.0) + if interrupted: + self._hook.logger.info("interrupted") + break except Exception as err: # pylint: disable=broad-except self._hook.logger.error("Background thread caught exception: %s.", err) self.err = err @@ -37,6 +47,7 @@ class BGJob(threading.Thread): def kill(self): """Kill the background job.""" self.__is_alive = False + self._interrupt_event.set() class BGHook(interface.Hook): @@ -46,8 +57,13 @@ class BGHook(interface.Hook): # By default, we continuously run the background hook for the duration of the suite. DEFAULT_TESTS_PER_CYCLE = math.inf - def __init__(self, hook_logger, fixture, desc, tests_per_cycle=None): - """Initialize the background hook.""" + def __init__(self, hook_logger, fixture, desc, tests_per_cycle=None, loop_delay_ms=None): + """ + Initialize the background hook. + + 'tests_per_cycle' or 'loop_delay_ms' can be used to configure how often the background job + is restarted, and how often run_action() is called, respectively. + """ interface.Hook.__init__(self, hook_logger, fixture, desc) self.logger = hook_logger @@ -57,15 +73,21 @@ class BGHook(interface.Hook): self._test_num = 0 # The number of tests we execute before restarting the background hook. self._tests_per_cycle = self.DEFAULT_TESTS_PER_CYCLE if tests_per_cycle is None else tests_per_cycle + self._loop_delay_ms = loop_delay_ms def run_action(self): - """Perform an action. This function will be called continuously in the BgJob.""" + """ + Perform an action. This function will be called continuously in the BgJob. + + If a sleep_delay_ms was given, that many milliseconds of sleep will happen between each + invocation. + """ raise NotImplementedError def before_suite(self, test_report): """Start the background thread.""" self.logger.info("Starting the background thread.") - self._background_job = BGJob(self) + self._background_job = BGJob(self, self._loop_delay_ms) self._background_job.start() def after_suite(self, test_report, teardown_flag=None): @@ -86,7 +108,7 @@ class BGHook(interface.Hook): return self.logger.info("Restarting the background thread.") - self._background_job = BGJob(self) + self._background_job = BGJob(self, self._loop_delay_ms) self._background_job.start() def after_test(self, test, test_report): diff --git a/buildscripts/resmokelib/testing/hooks/run_query_stats.py b/buildscripts/resmokelib/testing/hooks/run_query_stats.py new file mode 100644 index 00000000000..736c5e261c7 --- /dev/null +++ b/buildscripts/resmokelib/testing/hooks/run_query_stats.py @@ -0,0 +1,83 @@ +""" +Test hook for verifying $queryStats collects expected metrics and can redact query shapes. + +This runs in the background as other tests are ongoing. +""" + +from bson import binary +import pymongo.errors +from buildscripts.resmokelib.testing.hooks.interface import Hook + +QUERY_STATS_NOT_ENABLED_CODES = [224, 7373500, 6579000] + + +class RunQueryStats(Hook): + """Runs $queryStats after every test, and clears the query stats store before every test.""" + + IS_BACKGROUND = False + + def __init__(self, hook_logger, fixture, allow_feature_not_supported=False): + """Initialize the RunQueryStats hook. + + Args: + hook_logger: the logger instance for this hook. + fixture: the target fixture (replica sets or a sharded cluster). + allow_feature_not_supported: absorb 'QueryFeatureNotAllowed' errors when calling + $queryStats. This is to support fuzzer suites that may manipulate the FCV. + """ + description = "Read query stats data after each test." + super().__init__(hook_logger, fixture, description) + self.client = self.fixture.mongo_client() + self.hmac_key = binary.Binary(("0" * 32).encode('utf-8'), 8) + self.allow_feature_not_supported = allow_feature_not_supported + + def verify_query_stats(self, querystats_spec): + """Verify a $queryStats call has all the right properties.""" + query_stats_pipeline = [ + {"$queryStats": querystats_spec}, + # SERVER-90921: The pymongo version we use on this branch has trouble parsing invalid + # DBRefs, which can be produced by the 'key' field. We'll overwrite that field with a + # dummy one, since the contents aren't important for this test/check. + {"$set": {"key": "Redacted due to issues with DBRefs"}} + ] + try: + with self.client.admin.aggregate(query_stats_pipeline) as cursor: + nreturned = 0 + for operation in cursor: + assert "key" in operation + assert "metrics" in operation + assert "asOf" in operation + nreturned += 1 + self.logger.info("Found %d query stats entries.", nreturned) + except pymongo.errors.OperationFailure as err: + if self.allow_feature_not_supported and err.code in QUERY_STATS_NOT_ENABLED_CODES: + self.logger.info("Encountered an error while running $queryStats. " + "$queryStats will not be run for this test.") + else: + raise err + + def after_test(self, test, test_report): + """After the test, make sure we can ingest the query stats, with and without hmac.""" + self.verify_query_stats({}) + self.verify_query_stats( + {"transformIdentifiers": {"algorithm": "hmac-sha-256", "hmacKey": self.hmac_key}}) + + # Log the number of evictions we encountered. + server_status = self.client.admin.command({"serverStatus": 1}) + num_evicted_entries = server_status["metrics"]["queryStats"]["numEvicted"] + if num_evicted_entries > 0: + self.logger.info("Evicted %d query stats entries during test execution.", + num_evicted_entries) + + def before_test(self, test, test_report): + """Before the test, reset the contents of the query stats store.""" + try: + # Clear out all existing entries, then reset the size cap. + self.client.admin.command("setParameter", 1, internalQueryStatsCacheSize="0%") + self.client.admin.command("setParameter", 1, internalQueryStatsCacheSize="1%") + except pymongo.errors.OperationFailure as err: + if self.allow_feature_not_supported and err.code in QUERY_STATS_NOT_ENABLED_CODES: + self.logger.info("Encountered an error while configuring the query stats store. " + "Query stats will not be collected for this test.") + else: + raise err |