diff --git a/buildscripts/powercycle/plugins.py b/buildscripts/powercycle/plugins.py index 8a400ed9cc2..78cc95cbe7f 100644 --- a/buildscripts/powercycle/plugins.py +++ b/buildscripts/powercycle/plugins.py @@ -153,8 +153,8 @@ class SetUpEC2Instance(PowercycleCommand): # Sixth operation - # Set up curator to collect system & process stats on remote. - variant = "windows-64" if self.is_windows() else "ubuntu1604" - curator_hash = "117d1a65256ff78b6d15ab79a1c7088443b936d0" + variant = "windows" if self.is_windows() else "ubuntu1604" + curator_hash = "b0c3c0fc68bce26d9572796d6bed3af4a298e30e" curator_url = f"https://s3.amazonaws.com/boxes.10gen.com/build/curator/curator-dist-{variant}-{curator_hash}.tar.gz" cmds = f"curl -s {curator_url} | tar -xzv" monitor_system_file = powercycle_constants.MONITOR_SYSTEM_FILE diff --git a/buildscripts/resmokelib/core/jasper.proto b/buildscripts/resmokelib/core/jasper.proto index 17ed53e2ea6..85a064755fb 100644 --- a/buildscripts/resmokelib/core/jasper.proto +++ b/buildscripts/resmokelib/core/jasper.proto @@ -34,9 +34,10 @@ message BufferOptions { enum LogFormat { LOGFORMATUNKNOWN = 0; - LOGFORMATDEFAULT = 1; + LOGFORMATPLAIN = 1; LOGFORMATJSON = 2; - LOGFORMATPLAIN = 3; + LOGFORMATBSON = 3; + LOGFORMATDEFAULT = 4; } message BaseOptions { @@ -104,19 +105,20 @@ message BuildloggerV3Info { int32 execution = 6; string test_name = 7; int32 trial = 8; - string process_name = 9; + string proc_name = 9; LogFormat format = 10; repeated string tags = 11; map args = 12; bool mainline = 13; - int64 max_buffer_size = 14; - int64 flush_interval = 15; - bool disable_new_line_check = 16; - string base_address = 17; - string rpc_port = 18; - bool insecure = 19; - string username = 20; - string api_key = 21; + string prefix = 14; + int64 max_buffer_size = 15; + int64 flush_interval = 16; + bool disable_new_line_check = 17; + string base_address = 18; + string rpc_port = 19; + bool insecure = 20; + string username = 21; + string api_key = 22; } message BuildloggerV3Options { @@ -302,7 +304,6 @@ message EventName { message ScriptingHarnessID { string id = 1; - bool setup = 2; } message ScriptingOptionsGolang { @@ -387,18 +388,18 @@ message ScriptingHarnessTestResponse { } message LoggingCacheCreateArgs { - string name = 1; + string id = 1; OutputOptions options = 2; } message LoggingCacheArgs { - string name = 1; + string id = 1; } message LoggingCacheInstance { OperationOutcome outcome = 1 ; string id = 2; - string manager = 3; + string managerID = 3; google.protobuf.Timestamp accessed = 4; } @@ -442,6 +443,7 @@ service JasperProcessManager { rpc Signal(SignalProcess) returns (OperationOutcome); rpc Clear(google.protobuf.Empty) returns (OperationOutcome); rpc Close(google.protobuf.Empty) returns (OperationOutcome); + rpc WriteFile(stream WriteFileInfo) returns (OperationOutcome); // Process functions rpc TagProcess(ProcessTags) returns (OperationOutcome); @@ -451,9 +453,7 @@ service JasperProcessManager { rpc Wait(JasperProcessID) returns (OperationOutcome); rpc Respawn(JasperProcessID) returns (ProcessInfo); - // ScriptingHarness functions - rpc ScriptingHarnessCreate(ScriptingOptions) returns (ScriptingHarnessID); - rpc ScriptingHarnessCheck(ScriptingHarnessID) returns (OperationOutcome); + // scripting.Harness functions rpc ScriptingHarnessSetup(ScriptingHarnessID) returns (OperationOutcome); rpc ScriptingHarnessCleanup(ScriptingHarnessID) returns (OperationOutcome); rpc ScriptingHarnessRun(ScriptingHarnessRunArgs) returns (OperationOutcome); @@ -461,14 +461,18 @@ service JasperProcessManager { rpc ScriptingHarnessRunScript(ScriptingHarnessRunScriptArgs) returns (OperationOutcome); rpc ScriptingHarnessTest(ScriptingHarnessTestArgs) returns (ScriptingHarnessTestResponse); - // Logging functions + // LoggingCache functions rpc LoggingCacheCreate(LoggingCacheCreateArgs) returns (LoggingCacheInstance); rpc LoggingCacheGet(LoggingCacheArgs) returns (LoggingCacheInstance); rpc LoggingCacheRemove(LoggingCacheArgs) returns (OperationOutcome); + rpc LoggingCacheCloseAndRemove(LoggingCacheArgs) returns (OperationOutcome); + rpc LoggingCacheClear(google.protobuf.Empty) returns (OperationOutcome); rpc LoggingCacheLen(google.protobuf.Empty) returns (LoggingCacheSize); rpc LoggingCachePrune(google.protobuf.Timestamp) returns (OperationOutcome); // Remote specific functions + rpc ScriptingHarnessCreate(ScriptingOptions) returns (ScriptingHarnessID); + rpc ScriptingHarnessGet(ScriptingHarnessID) returns (OperationOutcome); rpc Status(google.protobuf.Empty) returns (StatusResponse); rpc ConfigureCache(CacheOptions) returns (OperationOutcome); rpc DownloadFile(DownloadInfo) returns (OperationOutcome); @@ -476,6 +480,5 @@ service JasperProcessManager { rpc GetLogStream(LogRequest) returns (LogStream); rpc GetBuildloggerURLs(JasperProcessID) returns (BuildloggerURLs); rpc SignalEvent(EventName) returns (OperationOutcome); - rpc WriteFile(stream WriteFileInfo) returns (OperationOutcome); rpc SendMessages(LoggingPayload) returns (OperationOutcome); } diff --git a/buildscripts/resmokelib/core/jasper_process.py b/buildscripts/resmokelib/core/jasper_process.py index 1e741631397..64cf23edacc 100644 --- a/buildscripts/resmokelib/core/jasper_process.py +++ b/buildscripts/resmokelib/core/jasper_process.py @@ -8,6 +8,8 @@ try: except ImportError: pass +import time + from buildscripts.resmokelib import config from buildscripts.resmokelib import errors from buildscripts.resmokelib.core import process as _process @@ -21,7 +23,8 @@ class Process(_process.Process): pb = None rpc = None - def __init__(self, logger, args, env=None, env_vars=None, job_num=None, test_id=None): # pylint: disable=too-many-arguments + def __init__( # pylint: disable=too-many-arguments + self, logger, args, env=None, env_vars=None, job_num=None, test_id=None): """Initialize the process with the specified logger, arguments, and environment.""" _process.Process.__init__(self, logger, args, env=env, env_vars=env_vars) self._id = None @@ -33,8 +36,11 @@ class Process(_process.Process): def start(self): """Start the process and the logger pipes for its stdout and stderr.""" + # Add current timestamp to process name since processes may restart + # within a job. + process_name = "{}-{}".format(self.args[0], time.monotonic()) logger = get_logger_config(group_id=self.job_num, test_id=self.test_id, - process_name=self.args[0]) + process_name=process_name, prefix=self.logger.name) output_opts = self.pb.OutputOptions(loggers=[logger]) create_options = self.pb.CreateOptions( args=self.args, diff --git a/buildscripts/resmokelib/core/programs.py b/buildscripts/resmokelib/core/programs.py index 179938404de..bfc43895ff8 100644 --- a/buildscripts/resmokelib/core/programs.py +++ b/buildscripts/resmokelib/core/programs.py @@ -12,6 +12,7 @@ from buildscripts.resmokelib import config from buildscripts.resmokelib import utils from buildscripts.resmokelib.core import jasper_process from buildscripts.resmokelib.core import process +from buildscripts.resmokelib.logging import loggers from buildscripts.resmokelib.multiversionconstants import LAST_LTS_MONGOD_BINARY from buildscripts.resmokelib.multiversionconstants import LAST_LTS_MONGOS_BINARY @@ -118,7 +119,7 @@ def _add_testing_set_parameters(suite_set_parameters): def mongod_program( # pylint: disable=too-many-branches,too-many-statements - logger, executable=None, process_kwargs=None, **kwargs): + logger, job_num, executable=None, process_kwargs=None, **kwargs): """Return a Process instance that starts mongod arguments constructed from 'kwargs'.""" executable = utils.default_if_none(executable, config.DEFAULT_MONGOD_EXECUTABLE) @@ -271,10 +272,11 @@ def mongod_program( # pylint: disable=too-many-branches,too-many-statements _set_keyfile_permissions(kwargs) process_kwargs = utils.default_if_none(process_kwargs, {}) + process_kwargs["job_num"] = job_num return make_process(logger, args, **process_kwargs) -def mongos_program(logger, executable=None, process_kwargs=None, **kwargs): +def mongos_program(logger, job_num, test_id=None, executable=None, process_kwargs=None, **kwargs): """Return a Process instance that starts a mongos with arguments constructed from 'kwargs'.""" executable = utils.default_if_none(executable, config.DEFAULT_MONGOS_EXECUTABLE) @@ -301,11 +303,13 @@ def mongos_program(logger, executable=None, process_kwargs=None, **kwargs): _set_keyfile_permissions(kwargs) process_kwargs = utils.default_if_none(process_kwargs, {}) + process_kwargs["job_num"] = job_num + process_kwargs["test_id"] = test_id return make_process(logger, args, **process_kwargs) def mongo_shell_program( # pylint: disable=too-many-arguments,too-many-branches,too-many-locals,too-many-statements - logger, job_num=None, test_id=None, executable=None, connection_string=None, filename=None, + logger, job_num, test_id=None, executable=None, connection_string=None, filename=None, process_kwargs=None, **kwargs): """Return a Process instance that starts a mongo shell. @@ -503,7 +507,8 @@ def _format_shell_vars(sb, paths, value): _format_shell_vars(sb, paths + [subkey], value[subkey]) -def dbtest_program(logger, executable=None, suites=None, process_kwargs=None, **kwargs): +def dbtest_program(logger, job_num, test_id=None, executable=None, suites=None, process_kwargs=None, + **kwargs): # pylint: disable=too-many-arguments """Return a Process instance that starts a dbtest with arguments constructed from 'kwargs'.""" executable = utils.default_if_none(executable, config.DEFAULT_DBTEST_EXECUTABLE) @@ -519,17 +524,19 @@ def dbtest_program(logger, executable=None, suites=None, process_kwargs=None, ** if config.FLOW_CONTROL is not None: kwargs["flowControl"] = (config.FLOW_CONTROL == "on") - return generic_program(logger, args, process_kwargs=process_kwargs, **kwargs) + return generic_program(logger, args, job_num, test_id=test_id, process_kwargs=process_kwargs, + **kwargs) -def genny_program(logger, executable=None, process_kwargs=None, **kwargs): +def genny_program(logger, job_num, test_id=None, executable=None, process_kwargs=None, **kwargs): """Return a Process instance that starts a genny executable with arguments constructed from 'kwargs'.""" executable = utils.default_if_none(executable, config.DEFAULT_GENNY_EXECUTABLE) args = [executable] - return generic_program(logger, args, process_kwargs, **kwargs) + return generic_program(logger, args, job_num, test_id=test_id, process_kwargs=process_kwargs, + **kwargs) -def generic_program(logger, args, process_kwargs=None, **kwargs): +def generic_program(logger, args, job_num, test_id=None, process_kwargs=None, **kwargs): """Return a Process instance that starts an arbitrary executable. The executable arguments are constructed from 'kwargs'. @@ -543,6 +550,8 @@ def generic_program(logger, args, process_kwargs=None, **kwargs): _apply_kwargs(args, kwargs) process_kwargs = utils.default_if_none(process_kwargs, {}) + process_kwargs["job_num"] = job_num + process_kwargs["test_id"] = test_id return make_process(logger, args, **process_kwargs) diff --git a/buildscripts/resmokelib/logging/jasper_logger.py b/buildscripts/resmokelib/logging/jasper_logger.py index abc3269b734..5ac2dcb1316 100644 --- a/buildscripts/resmokelib/logging/jasper_logger.py +++ b/buildscripts/resmokelib/logging/jasper_logger.py @@ -1,38 +1,125 @@ """Jasper logging handlers and helpers.""" +try: + import grpc +except ImportError: + pass + +import logging import os +import time from buildscripts.resmokelib import config +from buildscripts.resmokelib import utils -def get_logger_config(group_id="", test_id="", process_name=""): +def get_test_log_url(group_id, test_id): + """Return a URL to the test log in cedar.""" + + return "https://{}/rest/v1/buildlogger/test_name/{}/{}/group/{}?execution={}".format( + config.CEDAR_URL, config.EVERGREEN_TASK_ID, test_id, group_id, config.EVERGREEN_EXECUTION) + + +def get_logger_config(group_id=None, test_id=None, process_name=None, prefix=None, trial=None): + # pylint: disable=too-many-locals """Return the jasper logger config.""" import jasper.jasper_pb2 as pb username = os.getenv("CEDAR_USERNAME", default="") api_key = os.getenv("CEDAR_API_KEY", default="") + test_id = utils.default_if_none(test_id, "") + process_name = utils.default_if_none(process_name, "") + prefix = utils.default_if_none(prefix, "") + trial = utils.default_if_none(trial, 0) logger_config = pb.LoggerConfig() log_level = pb.LogLevel(threshold=30, default=30) log_format = pb.LogFormat.Value("LOGFORMATPLAIN") - if config.EVERGREEN_TASK_ID and group_id: + if config.EVERGREEN_TASK_ID and group_id is not None: buildlogger_info = pb.BuildloggerV3Info( project=config.EVERGREEN_PROJECT_NAME, version=config.EVERGREEN_VERSION_ID, variant=config.EVERGREEN_VARIANT_NAME, task_name=config.EVERGREEN_TASK_NAME, task_id=config.EVERGREEN_TASK_ID, execution=config.EVERGREEN_EXECUTION, - test_name=str(test_id), process_name=process_name, format=log_format, tags=[ + test_name=str(test_id), proc_name=process_name, trial=trial, format=log_format, tags=[ str(group_id) - ], base_address=config.CEDAR_URL, rpc_port=config.CEDAR_RPC_PORT, username=username, - api_key=api_key) + ], prefix=prefix, base_address=config.CEDAR_URL, rpc_port=config.CEDAR_RPC_PORT, + username=username, api_key=api_key) buildlogger_options = pb.BuildloggerV3Options(buildloggerv3=buildlogger_info, level=log_level) logger_config.buildloggerv3.CopyFrom(buildlogger_options) else: buffered = pb.BufferOptions() base_opts = pb.BaseOptions(format=log_format, level=log_level, buffer=buffered) - log_opts = pb.DefaultLoggerOptions(base=base_opts) + log_opts = pb.DefaultLoggerOptions(prefix=prefix, base=base_opts) logger_config.default.CopyFrom(log_opts) return logger_config + + +class JasperHandler(logging.Handler): + """Jasper logger handler.""" + + pb = None + rpc = None + + def __init__(self, name, group_id, test_id=None): + """Initialize the jasper handler. + + The name uniquely identifies the logger within the logging cache. Group + id is required for cedar buildlogger, test id and trial are optional. + """ + logging.Handler.__init__(self) + self.name = "{}-{}".format(name, time.monotonic()) + self.closed = False + + logger_config = get_logger_config(group_id=group_id, test_id=test_id, + process_name=self.name) + output_opts = self.pb.OutputOptions(loggers=[logger_config]) + create_args = self.pb.LoggingCacheCreateArgs(id=self.name, options=output_opts) + + self.stub = self.rpc.JasperProcessManagerStub( + grpc.insecure_channel(config.JASPER_CONNECTION_STR)) + try: + instance = self.stub.LoggingCacheCreate(create_args) + if not instance.outcome.success: + raise RuntimeError("Failed to setup jasper handler: {}".format( + instance.outcome.text)) + except grpc.RpcError as rpc_err: + raise RuntimeError("Failed to setup jasper handler with status code {}: {}".format( + rpc_err.code(), rpc_err.details())) + + def emit(self, record): + """Emit a record to the jasper logging backend.""" + record = self.format(record) + + log_format = self.pb.LoggingPayloadFormat.Value("FORMATSTRING") + log_data = self.pb.LoggingPayloadData() + log_data.msg = record + logging_payload = self.pb.LoggingPayload(LoggerID=self.name, priority=40, format=log_format, + data=[log_data]) + try: + outcome = self.stub.SendMessages(logging_payload) + if not outcome.success: + raise RuntimeError("Failed to send log message via jasper: {}".format(outcome.text)) + except grpc.RpcError as rpc_err: + raise RuntimeError( + "Failed to send log message via jasper with status code {}: {}".format( + rpc_err.code(), rpc_err.details())) + + def close(self): + """Close the logging handler.""" + logging.Handler.close(self) + + if not self.closed: + self.closed = True + + args = self.pb.LoggingCacheArgs(id=self.name) + try: + outcome = self.stub.LoggingCacheCloseAndRemove(args) + if not outcome.success: + raise RuntimeError("Failed to close jasper logger: {}".format(outcome.text)) + except grpc.RpcError as rpc_err: + raise RuntimeError("Failed to close jasper logger with status code {}: {}".format( + rpc_err.code(), rpc_err.details())) diff --git a/buildscripts/resmokelib/logging/loggers.py b/buildscripts/resmokelib/logging/loggers.py index 4733d0081d8..328e75cf49c 100644 --- a/buildscripts/resmokelib/logging/loggers.py +++ b/buildscripts/resmokelib/logging/loggers.py @@ -10,6 +10,7 @@ from buildscripts.resmokelib import errors from buildscripts.resmokelib.core import redirect as redirect_lib from buildscripts.resmokelib.logging import buildlogger from buildscripts.resmokelib.logging import formatters +from buildscripts.resmokelib.logging import jasper_logger _DEFAULT_FORMAT = "[%(name)s] %(message)s" @@ -159,7 +160,10 @@ def new_fixture_logger(fixture_class, job_num): name = "%s:job%d" % (fixture_class, job_num) logger = logging.Logger(name) logger.parent = ROOT_FIXTURE_LOGGER - _add_build_logger_handler(logger, job_num) + if config.SPAWN_USING == "jasper": + _add_jasper_logger_handler(logger, job_num) + else: + _add_build_logger_handler(logger, job_num) _FIXTURE_LOGGER_REGISTRY[job_num] = logger return logger @@ -184,7 +188,7 @@ def new_testqueue_logger(test_kind): #pylint: disable=too-many-arguments -def new_test_logger(test_shortname, test_basename, command, parent, job_num, job_logger): +def new_test_logger(test_shortname, test_basename, command, parent, job_num, test_id, job_logger): """Create a new test logger that will be a child of the given parent.""" name = "%s:%s" % (parent.name, test_shortname) logger = logging.Logger(name) @@ -210,6 +214,10 @@ def new_test_logger(test_shortname, test_basename, command, parent, job_num, job return (test_id, url) + if config.SPAWN_USING == "jasper": + _add_jasper_logger_handler(logger, job_num, test_id=test_id) + return (logger, jasper_logger.get_test_log_url(job_num, test_id)) + (test_id, url) = _get_test_endpoint(job_num, test_basename, command, job_logger) _add_build_logger_handler(logger, job_num, test_id) return (logger, url) @@ -274,6 +282,12 @@ def _get_buildlogger_handler_info(logger_info): return None +def _add_jasper_logger_handler(logger, job_num, test_id=None): + handler = jasper_logger.JasperHandler(logger.name, job_num, test_id) + handler.setFormatter(formatters.ISO8601Formatter(_DEFAULT_FORMAT)) + logger.addHandler(handler) + + def _fallback_buildlogger_handler(include_logger_name=True): """Return a handler that writes to stderr.""" if include_logger_name: diff --git a/buildscripts/resmokelib/run/__init__.py b/buildscripts/resmokelib/run/__init__.py index 99bab7305bd..a0971357bd9 100644 --- a/buildscripts/resmokelib/run/__init__.py +++ b/buildscripts/resmokelib/run/__init__.py @@ -123,6 +123,8 @@ class TestRunner(Subcommand): # pylint: disable=too-many-instance-attributes # self._exit_logging() may never return when the log output is incomplete. # Our workaround is to call os._exit(). self._exit_logging() + if config.SPAWN_USING == "jasper": + self._exit_jasper() def list_suites(self): """List the suites that are available to execute.""" @@ -205,8 +207,6 @@ class TestRunner(Subcommand): # pylint: disable=too-many-instance-attributes exit_code = max(suite.return_code for suite in suites) self.exit(exit_code) finally: - if config.SPAWN_USING == "jasper": - self._exit_jasper() self._exit_archival() if suites: reportfile.write(suites) @@ -357,7 +357,7 @@ class TestRunner(Subcommand): # pylint: disable=too-many-instance-attributes curator_path = "build/curator" if sys.platform == "win32": curator_path += ".exe" - git_hash = "d11f83290729dc42138af106fe01bc0714c24a8b" + git_hash = "b0c3c0fc68bce26d9572796d6bed3af4a298e30e" curator_exists = os.path.isfile(curator_path) curator_same_version = False if curator_exists: @@ -398,6 +398,8 @@ class TestRunner(Subcommand): # pylint: disable=too-many-instance-attributes jasper_process.Process.pb = jasper_pb2 jasper_process.Process.rpc = jasper_pb2_grpc + logging.jasper_logger.JasperHandler.pb = jasper_pb2 + logging.jasper_logger.JasperHandler.rpc = jasper_pb2_grpc jasper_port = config.BASE_PORT - 1 jasper_conn_str = "localhost:%d" % jasper_port diff --git a/buildscripts/resmokelib/testing/fixtures/shardedcluster.py b/buildscripts/resmokelib/testing/fixtures/shardedcluster.py index dd8164c034c..e8f9ac61564 100644 --- a/buildscripts/resmokelib/testing/fixtures/shardedcluster.py +++ b/buildscripts/resmokelib/testing/fixtures/shardedcluster.py @@ -406,8 +406,8 @@ class _MongoSFixture(interface.Fixture): port=self.port) self.mongos_options["logappend"] = "" - mongos = core.programs.mongos_program(self.logger, executable=self.mongos_executable, - **self.mongos_options) + mongos = core.programs.mongos_program( + self.logger, self.job_num, executable=self.mongos_executable, **self.mongos_options) try: self.logger.info("Starting mongos on port %d...\n%s", self.port, mongos.as_command()) mongos.start() diff --git a/buildscripts/resmokelib/testing/fixtures/standalone.py b/buildscripts/resmokelib/testing/fixtures/standalone.py index 56f4ca960a1..e8252c1cb52 100644 --- a/buildscripts/resmokelib/testing/fixtures/standalone.py +++ b/buildscripts/resmokelib/testing/fixtures/standalone.py @@ -66,8 +66,8 @@ class MongoDFixture(interface.Fixture): self.mongod_options["port"] = core.network.PortAllocator.next_fixture_port(self.job_num) self.port = self.mongod_options["port"] - mongod = core.programs.mongod_program(self.logger, executable=self.mongod_executable, - **self.mongod_options) + mongod = core.programs.mongod_program( + self.logger, self.job_num, executable=self.mongod_executable, **self.mongod_options) try: self.logger.info("Starting mongod on port %d...\n%s", self.port, mongod.as_command()) mongod.start() diff --git a/buildscripts/resmokelib/testing/fixtures/yesfixture.py b/buildscripts/resmokelib/testing/fixtures/yesfixture.py index 860e054a6c2..3a22e1a6514 100644 --- a/buildscripts/resmokelib/testing/fixtures/yesfixture.py +++ b/buildscripts/resmokelib/testing/fixtures/yesfixture.py @@ -35,7 +35,7 @@ class YesFixture(interface.Fixture): # pylint: disable=abstract-method def _make_process(self, index): logger = logging.loggers.new_fixture_node_logger(self.__class__.__name__, self.job_num, "yes{:d}".format(index)) - return programs.generic_program(logger, ["yes", self.__message]) + return programs.generic_program(logger, self.job_num, ["yes", self.__message]) def _do_teardown(self, mode=None): running_at_start = self.is_running() diff --git a/buildscripts/resmokelib/testing/hooks/wait_for_replication.py b/buildscripts/resmokelib/testing/hooks/wait_for_replication.py index ad730920d44..c771a3008cb 100644 --- a/buildscripts/resmokelib/testing/hooks/wait_for_replication.py +++ b/buildscripts/resmokelib/testing/hooks/wait_for_replication.py @@ -35,7 +35,8 @@ class WaitForReplication(interface.Hook): jsTestLog("Ignoring shutdown error in quiesce mode"); }}""" shell_options = {"nodb": "", "eval": js_cmds.format(client_conn)} - shell_proc = core.programs.mongo_shell_program(self.hook_logger, **shell_options) + shell_proc = core.programs.mongo_shell_program(self.hook_logger, self.fixture.job_num, + **shell_options) shell_proc.start() return_code = shell_proc.wait() if return_code: diff --git a/buildscripts/resmokelib/testing/report.py b/buildscripts/resmokelib/testing/report.py index d16a37fcf23..48fc8a69247 100644 --- a/buildscripts/resmokelib/testing/report.py +++ b/buildscripts/resmokelib/testing/report.py @@ -120,8 +120,10 @@ class TestReport(unittest.TestResult): # pylint: disable=too-many-instance-attr self.num_dynamic += 1 # Set up the test-specific logger. - (test_logger, url_endpoint) = logging.loggers.new_test_logger( - test.short_name(), test.basename(), command, test.logger, self.job_num, self.job_logger) + (test_logger, url_endpoint) = logging.loggers.new_test_logger(test.short_name(), + test.basename(), command, + test.logger, self.job_num, + test.id(), self.job_logger) test_info.url_endpoint = url_endpoint if self.logging_prefix is not None: test_logger.info(self.logging_prefix) diff --git a/buildscripts/resmokelib/testing/testcases/benchmark_test.py b/buildscripts/resmokelib/testing/testcases/benchmark_test.py index 9902bd503ef..88ce2ee1436 100644 --- a/buildscripts/resmokelib/testing/testcases/benchmark_test.py +++ b/buildscripts/resmokelib/testing/testcases/benchmark_test.py @@ -81,4 +81,6 @@ class BenchmarkTestCase(interface.ProcessTestCase): return self.bm_executable + ".json" def _make_process(self): - return core.programs.generic_program(self.logger, [self.bm_executable], **self.bm_options) + return core.programs.generic_program(self.logger, [self.bm_executable], + self.fixture.job_num, test_id=self._id, + **self.bm_options) diff --git a/buildscripts/resmokelib/testing/testcases/cpp_integration_test.py b/buildscripts/resmokelib/testing/testcases/cpp_integration_test.py index 0b6573bb889..f6e99eb9bea 100644 --- a/buildscripts/resmokelib/testing/testcases/cpp_integration_test.py +++ b/buildscripts/resmokelib/testing/testcases/cpp_integration_test.py @@ -26,4 +26,5 @@ class CPPIntegrationTestCase(interface.ProcessTestCase): def _make_process(self): return core.programs.generic_program(self.logger, [self.program_executable], + self.fixture.job_num, test_id=self._id, **self.program_options) diff --git a/buildscripts/resmokelib/testing/testcases/cpp_libfuzzer_test.py b/buildscripts/resmokelib/testing/testcases/cpp_libfuzzer_test.py index 112273062f8..ab2bc6063ac 100644 --- a/buildscripts/resmokelib/testing/testcases/cpp_libfuzzer_test.py +++ b/buildscripts/resmokelib/testing/testcases/cpp_libfuzzer_test.py @@ -31,6 +31,8 @@ class CPPLibfuzzerTestCase(interface.ProcessTestCase): default_args = [ self.program_executable, self.corpus_directory, "-max_len=100000", "-rss_limit_mb=5000" ] + self.program_options["job_num"] = self.fixture.job_num + self.program_options["test_id"] = self._id return core.programs.make_process(self.logger, default_args, **self.program_options) def _execute(self, process): diff --git a/buildscripts/resmokelib/testing/testcases/cpp_unittest.py b/buildscripts/resmokelib/testing/testcases/cpp_unittest.py index dea8ee0ad0e..08b4a7e0cbd 100644 --- a/buildscripts/resmokelib/testing/testcases/cpp_unittest.py +++ b/buildscripts/resmokelib/testing/testcases/cpp_unittest.py @@ -19,5 +19,7 @@ class CPPUnitTestCase(interface.ProcessTestCase): self.program_options = utils.default_if_none(program_options, {}).copy() def _make_process(self): + self.program_options["job_num"] = self.fixture.job_num + self.program_options["test_id"] = self._id return core.programs.make_process(self.logger, [self.program_executable], **self.program_options) diff --git a/buildscripts/resmokelib/testing/testcases/dbtest.py b/buildscripts/resmokelib/testing/testcases/dbtest.py index 1bb29adb3f7..3bb31a53d4f 100644 --- a/buildscripts/resmokelib/testing/testcases/dbtest.py +++ b/buildscripts/resmokelib/testing/testcases/dbtest.py @@ -50,7 +50,8 @@ class DBTestCase(interface.ProcessTestCase): utils.rmtree(self.dbtest_options["dbpath"], ignore_errors=True) def _make_process(self): - return core.programs.dbtest_program(self.logger, executable=self.dbtest_executable, + return core.programs.dbtest_program(self.logger, self.fixture.job_num, test_id=self._id, + executable=self.dbtest_executable, suites=[self.dbtest_suite], **self.dbtest_options) @staticmethod diff --git a/buildscripts/resmokelib/testing/testcases/gennylib_test.py b/buildscripts/resmokelib/testing/testcases/gennylib_test.py index de40a2a52f2..123f56d08d4 100644 --- a/buildscripts/resmokelib/testing/testcases/gennylib_test.py +++ b/buildscripts/resmokelib/testing/testcases/gennylib_test.py @@ -39,4 +39,4 @@ class GennyLibTestCase(interface.ProcessTestCase): def _make_process(self): return core.programs.generic_program(self.logger, [self.program_executable] + self.verbatim_arguments, - **self.program_options) + self.fixture.job_num, self._id, **self.program_options) diff --git a/buildscripts/resmokelib/testing/testcases/gennytest.py b/buildscripts/resmokelib/testing/testcases/gennytest.py index add7c5fc2c5..73fd3642103 100644 --- a/buildscripts/resmokelib/testing/testcases/gennytest.py +++ b/buildscripts/resmokelib/testing/testcases/gennytest.py @@ -39,4 +39,5 @@ class GennyTestCase(interface.ProcessTestCase): self.genny_options.setdefault("metrics-output-file", output_file) def _make_process(self): - return core.programs.genny_program(self.logger, self.genny_executable, **self.genny_options) + return core.programs.genny_program(self.logger, self.fixture.job_num, self._id, + self.genny_executable, **self.genny_options) diff --git a/buildscripts/resmokelib/testing/testcases/jsrunnerfile.py b/buildscripts/resmokelib/testing/testcases/jsrunnerfile.py index ece5e2ceb15..359631d3fab 100644 --- a/buildscripts/resmokelib/testing/testcases/jsrunnerfile.py +++ b/buildscripts/resmokelib/testing/testcases/jsrunnerfile.py @@ -47,6 +47,6 @@ class JSRunnerFileTestCase(interface.ProcessTestCase): def _make_process(self): return core.programs.mongo_shell_program( - self.logger, executable=self.shell_executable, + self.logger, self.fixture.job_num, test_id=self._id, executable=self.shell_executable, connection_string=self.fixture.get_driver_connection_url(), filename=self.test_runner_file, **self.shell_options) diff --git a/buildscripts/resmokelib/testing/testcases/jstest.py b/buildscripts/resmokelib/testing/testcases/jstest.py index 1a1658dd452..1bfaf3bb398 100644 --- a/buildscripts/resmokelib/testing/testcases/jstest.py +++ b/buildscripts/resmokelib/testing/testcases/jstest.py @@ -20,15 +20,15 @@ class _SingleJSTestCase(interface.ProcessTestCase): REGISTERED_NAME = registry.LEAVE_UNREGISTERED - def __init__(self, logger, js_filename, shell_executable=None, shell_options=None): + def __init__(self, logger, js_filename, test_id, shell_executable=None, shell_options=None): # pylint: disable=too-many-arguments """Initialize the _SingleJSTestCase with the JS file to run.""" - interface.ProcessTestCase.__init__(self, logger, "JSTest", js_filename) # Command line options override the YAML configuration. self.shell_executable = utils.default_if_none(config.MONGO_EXECUTABLE, shell_executable) self.js_filename = js_filename + self.test_id = test_id self.shell_options = utils.default_if_none(shell_options, {}).copy() def configure(self, fixture, *args, **kwargs): @@ -102,7 +102,7 @@ class _SingleJSTestCase(interface.ProcessTestCase): def _make_process(self): return core.programs.mongo_shell_program( - self.logger, job_num=self.fixture.job_num, test_id=self._id, + self.logger, self.fixture.job_num, test_id=self.test_id, executable=self.shell_executable, filename=self.js_filename, connection_string=self.fixture.get_driver_connection_url(), **self.shell_options) @@ -134,7 +134,7 @@ class JSTestCase(interface.ProcessTestCase): interface.ProcessTestCase.__init__(self, logger, "JSTest", js_filename) self.num_clients = JSTestCase.DEFAULT_CLIENT_NUM - self.test_case_template = _SingleJSTestCase(logger, js_filename, shell_executable, + self.test_case_template = _SingleJSTestCase(logger, js_filename, self._id, shell_executable, shell_options) def configure( # pylint: disable=arguments-differ,keyword-arg-before-vararg @@ -174,7 +174,7 @@ class JSTestCase(interface.ProcessTestCase): """Create and configure a _SingleJSTestCase to be run in a separate thread.""" shell_options = self._get_shell_options_for_thread(thread_id) - test_case = _SingleJSTestCase(logger, self.test_case_template.js_filename, + test_case = _SingleJSTestCase(logger, self.test_case_template.js_filename, self._id, self.test_case_template.shell_executable, shell_options) test_case.configure(self.fixture) diff --git a/buildscripts/resmokelib/testing/testcases/mongos_test.py b/buildscripts/resmokelib/testing/testcases/mongos_test.py index cfe6da23445..ce915b2a8d0 100644 --- a/buildscripts/resmokelib/testing/testcases/mongos_test.py +++ b/buildscripts/resmokelib/testing/testcases/mongos_test.py @@ -29,5 +29,5 @@ class MongosTestCase(interface.ProcessTestCase): self.options["test"] = "" def _make_process(self): - return core.programs.mongos_program(self.logger, executable=self.mongos_executable, - **self.options) + return core.programs.mongos_program(self.logger, self.fixture.job_num, test_id=self._id, + executable=self.mongos_executable, **self.options) diff --git a/buildscripts/resmokelib/testing/testcases/mql_model_haskell_test.py b/buildscripts/resmokelib/testing/testcases/mql_model_haskell_test.py index 3993e5ca9e5..c99d2a54f4b 100644 --- a/buildscripts/resmokelib/testing/testcases/mql_model_haskell_test.py +++ b/buildscripts/resmokelib/testing/testcases/mql_model_haskell_test.py @@ -36,7 +36,8 @@ class MqlModelHaskellTestCase(interface.ProcessTestCase): self.program_executable = execs[0] def _make_process(self): + program_opts = {"job_num": self.fixture.job_num, "test_id": self._id} return core.programs.make_process(self.logger, [ self.program_executable, "--test", self.json_test_file, "--prefix", self.top_level_dirname - ]) + ], **program_opts) diff --git a/buildscripts/resmokelib/testing/testcases/pytest.py b/buildscripts/resmokelib/testing/testcases/pytest.py index 46cd7d5afa8..fdb5eb1d4f5 100644 --- a/buildscripts/resmokelib/testing/testcases/pytest.py +++ b/buildscripts/resmokelib/testing/testcases/pytest.py @@ -17,7 +17,8 @@ class PyTestCase(interface.ProcessTestCase): def _make_process(self): return core.programs.generic_program( - self.logger, [sys.executable, "-m", "unittest", self.test_module_name]) + self.logger, [sys.executable, "-m", "unittest", self.test_module_name], 0, + test_id=self._id) @property def test_module_name(self): diff --git a/buildscripts/resmokelib/testing/testcases/sdam_json_test.py b/buildscripts/resmokelib/testing/testcases/sdam_json_test.py index b11bf068433..3318e8c6ccc 100644 --- a/buildscripts/resmokelib/testing/testcases/sdam_json_test.py +++ b/buildscripts/resmokelib/testing/testcases/sdam_json_test.py @@ -46,4 +46,6 @@ class SDAMJsonTestCase(interface.ProcessTestCase): command_line = [self.program_executable] command_line += ["--source-dir", self.TEST_DIR] command_line += ["-f", self.json_test_file] - return core.programs.make_process(self.logger, command_line) + self.program_options["job_num"] = self.fixture.job_num + self.program_options["test_id"] = self._id + return core.programs.make_process(self.logger, command_line, **self.program_options) diff --git a/buildscripts/resmokelib/testing/testcases/server_selection_json_test.py b/buildscripts/resmokelib/testing/testcases/server_selection_json_test.py index 8e0bbb30aab..b32c9dede9f 100644 --- a/buildscripts/resmokelib/testing/testcases/server_selection_json_test.py +++ b/buildscripts/resmokelib/testing/testcases/server_selection_json_test.py @@ -47,4 +47,6 @@ class ServerSelectionJsonTestCase(interface.ProcessTestCase): command_line = [self.program_executable] command_line += ["--source-dir", self.TEST_DIR] command_line += ["-f", self.json_test_file] - return core.programs.make_process(self.logger, command_line) + self.program_options["job_num"] = self.fixture.job_num + self.program_options["test_id"] = self._id + return core.programs.make_process(self.logger, command_line, **self.program_options) diff --git a/buildscripts/resmokelib/testing/testcases/tla_plus_test.py b/buildscripts/resmokelib/testing/testcases/tla_plus_test.py index 1d3fd4b6c84..de1fd2349f5 100644 --- a/buildscripts/resmokelib/testing/testcases/tla_plus_test.py +++ b/buildscripts/resmokelib/testing/testcases/tla_plus_test.py @@ -42,4 +42,5 @@ class TLAPlusTestCase(interface.ProcessTestCase): process_kwargs["env_vars"] = {"JAVA_BINARY": self.java_binary} return core.programs.generic_program(self.logger, ["sh", "model-check.sh", self.test_name], + self.fixture.job_num, test_id=self._id, process_kwargs=process_kwargs) diff --git a/buildscripts/tests/resmokelib/logging/test_loggers.py b/buildscripts/tests/resmokelib/logging/test_loggers.py index 2342228d0c6..321bde29ea5 100644 --- a/buildscripts/tests/resmokelib/logging/test_loggers.py +++ b/buildscripts/tests/resmokelib/logging/test_loggers.py @@ -59,7 +59,7 @@ class TestLoggers(unittest.TestCase): mock_parent = MagicMock() (logger, url) = loggers.new_test_logger("dummy_shortname", "dummy_basename", - "dummy_command", mock_parent, 88, MagicMock()) + "dummy_command", mock_parent, 88, 99, MagicMock()) self.assertEqual(logger.handlers[0], mock_handler) self.assertEqual(logger.parent, mock_parent) self.assertEqual(url, "dummy_url")