summaryrefslogtreecommitdiff
path: root/buildscripts/resmokelib
diff options
context:
space:
mode:
authorMax Hirschhorn <max.hirschhorn@mongodb.com>2018-06-12 19:26:55 -0500
committerMax Hirschhorn <max.hirschhorn@mongodb.com>2018-06-12 19:26:55 -0500
commit1d12fbc7362925399e8ad4304307cdffd1d60362 (patch)
tree6cf3d2d750d5f709561fb4b68aa972e8fb6c678f /buildscripts/resmokelib
parent2c33be816fac4e37ed04b13f0cf5ef55e2eda4e7 (diff)
downloadmongo-1d12fbc7362925399e8ad4304307cdffd1d60362.tar.gz
SERVER-35472 Avoid falling back to stderr in resmoke.py.
Instead a special return code of 75 is used to indicate that the log output would otherwise be incomplete. The incomplete log output state is ignored if all tests passed. (cherry picked from commit 6ad26a359f7bc366da13d433ed612ff22f69d323) (cherry picked from commit 8fae595c44b14aa61951ba413e293449c2b49866)
Diffstat (limited to 'buildscripts/resmokelib')
-rw-r--r--buildscripts/resmokelib/errors.py7
-rw-r--r--buildscripts/resmokelib/logging/buildlogger.py45
-rw-r--r--buildscripts/resmokelib/logging/loggers.py59
3 files changed, 69 insertions, 42 deletions
diff --git a/buildscripts/resmokelib/errors.py b/buildscripts/resmokelib/errors.py
index 8f49a567a79..a0bddfdbc23 100644
--- a/buildscripts/resmokelib/errors.py
+++ b/buildscripts/resmokelib/errors.py
@@ -18,7 +18,12 @@ class StopExecution(ResmokeError): # noqa: D204
class UserInterrupt(StopExecution): # noqa: D204
"""Exception raised when a user signals resmoke.py to unconditionally stop executing tests."""
- pass
+ EXIT_CODE = 130 # Simulate SIGINT as exit code.
+
+
+class LoggerRuntimeConfigError(StopExecution): # noqa: D204
+ """Exception raised when a logging handler couldn't be configured at runtime."""
+ EXIT_CODE = 75
class TestFailure(ResmokeError): # noqa: D204
diff --git a/buildscripts/resmokelib/logging/buildlogger.py b/buildscripts/resmokelib/logging/buildlogger.py
index 5fa52c85c69..2e48101d517 100644
--- a/buildscripts/resmokelib/logging/buildlogger.py
+++ b/buildscripts/resmokelib/logging/buildlogger.py
@@ -4,6 +4,7 @@ from __future__ import absolute_import
import functools
import json
+import threading
import requests
@@ -23,6 +24,20 @@ _SEND_AFTER_SECS = 10
# Initialized by resmokelib.logging.loggers.configure_loggers()
BUILDLOGGER_FALLBACK = None
+_INCOMPLETE_LOG_OUTPUT = threading.Event()
+
+
+def is_log_output_incomplete(): # noqa: D205,D400
+ """Return true if we failed to write all of the log output to the buildlogger server, and return
+ false otherwise.
+ """
+ return _INCOMPLETE_LOG_OUTPUT.is_set()
+
+
+def set_log_output_incomplete():
+ """Indicate that we failed to write all of the log output to the buildlogger server."""
+ _INCOMPLETE_LOG_OUTPUT.set()
+
def _log_on_error(func):
"""Provide decorator that causes exceptions to be logged by the "buildlogger" Logger instance.
@@ -35,6 +50,10 @@ def _log_on_error(func):
"""Provide wrapper function."""
try:
return func(*args, **kwargs)
+ except requests.HTTPError as err:
+ BUILDLOGGER_FALLBACK.error("Encountered an HTTP error: %s", err)
+ except requests.RequestException as err:
+ BUILDLOGGER_FALLBACK.error("Encountered a network error: %s", err)
except: # pylint: disable=bare-except
BUILDLOGGER_FALLBACK.exception("Encountered an error.")
return None
@@ -155,11 +174,12 @@ class _BaseBuildloggerHandler(handlers.BufferedHandler):
new_max_size)
self.max_size = new_max_size
return self._append_logs(log_lines_chunk)
- BUILDLOGGER_FALLBACK.exception("Encountered an error.")
- return 0
+ BUILDLOGGER_FALLBACK.error("Encountered an HTTP error: %s", err)
+ except requests.RequestException as err:
+ BUILDLOGGER_FALLBACK.error("Encountered a network error: %s", err)
except: # pylint: disable=bare-except
BUILDLOGGER_FALLBACK.exception("Encountered an error.")
- return 0
+ return 0
def _flush_buffer_with_lock(self, buf, close_called):
"""Ensure all logging output has been flushed to the buildlogger server.
@@ -175,14 +195,17 @@ class _BaseBuildloggerHandler(handlers.BufferedHandler):
if nb_sent:
self.retry_buffer = self.retry_buffer[nb_sent:]
if close_called and self.retry_buffer:
- # Request to the buildlogger server returned an error, so use the fallback logger to
- # avoid losing the log messages entirely.
- for (_, message) in self.retry_buffer:
- # TODO: construct an LogRecord instance equivalent to the one passed to the
- # process_record() method if we ever decide to log the time when the
- # LogRecord was created, e.g. using %(asctime)s in
- # _fallback_buildlogger_handler().
- BUILDLOGGER_FALLBACK.info(message)
+ # The request to the logkeeper returned an error. We discard the log output rather than
+ # writing the messages to the fallback logkeeper to avoid putting additional pressure on
+ # the Evergreen database.
+ BUILDLOGGER_FALLBACK.warning(
+ "Failed to flush all log output (%d messages) to logkeeper.", len(
+ self.retry_buffer))
+
+ # We set a flag to indicate that we failed to flush all log output to logkeeper so
+ # resmoke.py can exit with a special return code.
+ set_log_output_incomplete()
+
self.retry_buffer = []
diff --git a/buildscripts/resmokelib/logging/loggers.py b/buildscripts/resmokelib/logging/loggers.py
index d319928eb5f..deb3f6c38a2 100644
--- a/buildscripts/resmokelib/logging/loggers.py
+++ b/buildscripts/resmokelib/logging/loggers.py
@@ -7,6 +7,7 @@ import sys
from . import buildlogger
from . import formatters
+from .. import errors
_DEFAULT_FORMAT = "[%(name)s] %(message)s"
@@ -174,15 +175,18 @@ class JobLogger(BaseLogger):
BaseLogger.__init__(self, name, parent=parent)
self.job_num = job_num
self.fixture_root_logger = fixture_root_logger
- # create build_id if it should
if self.build_logger_server:
+ # If we're configured to log messages to the buildlogger server, then request a new
+ # build_id for this job.
self.build_id = self.build_logger_server.new_build_id("job%d" % job_num)
- if self.build_id:
- url = self.build_logger_server.get_build_log_url(self.build_id)
- parent.info("Writing output of job #%d to %s.", job_num, url)
- else:
- parent.info("Encountered an error configuring buildlogger for job #%d, falling"
- " back to stderr.", job_num)
+ if not self.build_id:
+ buildlogger.set_log_output_incomplete()
+ raise errors.LoggerRuntimeConfigError(
+ "Encountered an error configuring buildlogger for job #{:d}: Failed to get a"
+ " new build_id".format(job_num))
+
+ url = self.build_logger_server.get_build_log_url(self.build_id)
+ parent.info("Writing output of job #%d to %s.", job_num, url)
else:
self.build_id = None
@@ -193,14 +197,19 @@ class JobLogger(BaseLogger):
def new_test_logger(self, test_shortname, test_basename, command, parent):
"""Create a new test logger that will be a child of the given parent."""
if self.build_id:
+ # If we're configured to log messages to the buildlogger server, then request a new
+ # test_id for this test.
test_id = self.build_logger_server.new_test_id(self.build_id, test_basename, command)
- if test_id:
- url = self.build_logger_server.get_test_log_url(self.build_id, test_id)
- self.info("Writing output of %s to %s.", test_shortname, url)
- return TestLogger(test_shortname, parent, self.build_id, test_id, url)
- else:
- self.info("Encountered an error configuring buildlogger for test %s, falling"
- " back to stderr.", test_shortname)
+ if not test_id:
+ buildlogger.set_log_output_incomplete()
+ raise errors.LoggerRuntimeConfigError(
+ "Encountered an error configuring buildlogger for test {}: Failed to get a new"
+ " test_id".format(test_basename))
+
+ url = self.build_logger_server.get_test_log_url(self.build_id, test_id)
+ self.info("Writing output of %s to %s.", test_basename, url)
+ return TestLogger(test_shortname, parent, self.build_id, test_id, url)
+
return TestLogger(test_shortname, parent)
@@ -226,14 +235,9 @@ class TestLogger(BaseLogger):
logger_info = self.logging_config[TESTS_LOGGER_NAME]
handler_info = _get_buildlogger_handler_info(logger_info)
if handler_info is not None:
- if build_id and test_id:
- handler = self.build_logger_server.get_test_handler(build_id, test_id, handler_info)
- handler.setFormatter(self.get_formatter(logger_info))
- self.addHandler(handler)
- else:
- # The build_id or test_id could not be obtained from the build logger server, so
- # we're falling back to stderr.
- self.addHandler(_fallback_buildlogger_handler())
+ handler = self.build_logger_server.get_test_handler(build_id, test_id, handler_info)
+ handler.setFormatter(self.get_formatter(logger_info))
+ self.addHandler(handler)
def new_test_thread_logger(self, test_kind, thread_id):
"""Create a new child test thread logger."""
@@ -272,14 +276,9 @@ class FixtureLogger(BaseLogger):
logger_info = self.logging_config[FIXTURE_LOGGER_NAME]
handler_info = _get_buildlogger_handler_info(logger_info)
if handler_info is not None:
- if build_id:
- handler = self.build_logger_server.get_global_handler(build_id, handler_info)
- handler.setFormatter(self.get_formatter(logger_info))
- self.addHandler(handler)
- else:
- # The build_id could not be obtained from the build logger server, so we're
- # falling back to stderr.
- self.addHandler(_fallback_buildlogger_handler())
+ handler = self.build_logger_server.get_global_handler(build_id, handler_info)
+ handler.setFormatter(self.get_formatter(logger_info))
+ self.addHandler(handler)
def new_fixture_node_logger(self, node_name):
"""Create a new child FixtureNodeLogger."""