Fail the integration tests on warnings or errors.

benchmarks/envoy_proxy.py

@@ -92,9 +92,9 @@ def setUp(self):
                                                                port=proxy_server.server_port))
     self.proxy_server = proxy_server
 
-  def tearDown(self):
+  def tearDown(self, caplog):
     """Tear down the proxy and test server. Assert that both exit succesfully."""
-    super(InjectHttpProxyIntegrationTestBase, self).tearDown()
+    super(InjectHttpProxyIntegrationTestBase, self).tearDown(caplog)
     assert (self.proxy_server.stop() == 0)
 
   def getTestServerRootUri(self):
@@ -106,7 +106,7 @@ def getTestServerRootUri(self):
 
 
 @pytest.fixture(params=determineIpVersionsFromEnvironment())
-def inject_envoy_http_proxy_fixture(request, server_config, proxy_config):
+def inject_envoy_http_proxy_fixture(request, server_config, proxy_config, caplog):
   """Injects an Envoy proxy in front of the test server.
 
   NOTE: Depends on the proxy_config fixture, which must be explicitly imported
@@ -116,10 +116,11 @@ def inject_envoy_http_proxy_fixture(request, server_config, proxy_config):
     request: supplies the ip version.
     server_config: path to the server configuration template.
     proxy_config: path to the proxy configuration template.
+    caplog: The pytest `caplog` test fixture used to examine logged messages.
 
   Yields: a successfully set up InjectHttpProxyIntegrationTestBase instance.
   """
   fixture = InjectHttpProxyIntegrationTestBase(request.param, server_config, proxy_config)
   fixture.setUp()
   yield fixture
-  fixture.tearDown()
+  fixture.tearDown(caplog)

test/integration/integration_test_fixtures.py

@@ -123,8 +123,14 @@ def setUp(self):
     self.tag = "{timestamp}/{test_id}".format(timestamp=_TIMESTAMP, test_id=self._test_id)
     assert self._tryStartTestServers(), "Test server(s) failed to start"
 
-  def tearDown(self):
-    """Stop the server."""
+  def tearDown(self, caplog):
+    """Stop the server.
+
+    Fails the test if any warnings or errors were logged.
+
+    Args:
+      caplog: The pytest `caplog` test fixture used to examine logged messages.
+    """
     if self.grpc_service is not None:
       assert (self.grpc_service.stop() == 0)
 
@@ -134,6 +140,15 @@ def tearDown(self):
         any_failed = True
     assert (not any_failed)
 
+    warnings_and_errors = []
+    for when in ("setup", "call", "teardown"):
+      for record in caplog.get_records(when):
+        if record.levelno not in (logging.WARNING, logging.ERROR):
+          continue
+        warnings_and_errors.append(record.message)
+    if warnings_and_errors:
+      pytest.fail("warnings or errors encountered during testing:\n{}".format(warnings_and_errors))
+
   def _tryStartTestServers(self):
     for i in range(self._backend_count):
       test_server = NighthawkTestServer(self._nighthawk_test_server_path,
@@ -366,7 +381,7 @@ def server_config():
 
 
 @pytest.fixture(params=determineIpVersionsFromEnvironment())
-def http_test_server_fixture(request, server_config):
+def http_test_server_fixture(request, server_config, caplog):
   """Fixture for setting up a test environment with the stock http server configuration.
 
   Yields:
@@ -375,11 +390,11 @@ def http_test_server_fixture(request, server_config):
   f = HttpIntegrationTestBase(request.param, server_config)
   f.setUp()
   yield f
-  f.tearDown()
+  f.tearDown(caplog)
 
 
 @pytest.fixture(params=determineIpVersionsFromEnvironment())
-def https_test_server_fixture(request, server_config):
+def https_test_server_fixture(request, server_config, caplog):
   """Fixture for setting up a test environment with the stock https server configuration.
 
   Yields:
@@ -388,11 +403,11 @@ def https_test_server_fixture(request, server_config):
   f = HttpsIntegrationTestBase(request.param, server_config)
   f.setUp()
   yield f
-  f.tearDown()
+  f.tearDown(caplog)
 
 
 @pytest.fixture(params=determineIpVersionsFromEnvironment())
-def multi_http_test_server_fixture(request, server_config):
+def multi_http_test_server_fixture(request, server_config, caplog):
   """Fixture for setting up a test environment with multiple servers, using the stock http server configuration.
 
   Yields:
@@ -401,11 +416,11 @@ def multi_http_test_server_fixture(request, server_config):
   f = MultiServerHttpIntegrationTestBase(request.param, server_config, backend_count=3)
   f.setUp()
   yield f
-  f.tearDown()
+  f.tearDown(caplog)
 
 
 @pytest.fixture(params=determineIpVersionsFromEnvironment())
-def multi_https_test_server_fixture(request, server_config):
+def multi_https_test_server_fixture(request, server_config, caplog):
   """Fixture for setting up a test environment with multiple servers, using the stock https server configuration.
 
   Yields:
@@ -414,4 +429,4 @@ def multi_https_test_server_fixture(request, server_config):
   f = MultiServerHttpsIntegrationTestBase(request.param, server_config, backend_count=3)
   f.setUp()
   yield f
-  f.tearDown()
+  f.tearDown(caplog)

test/integration/nighthawk_test_server.py

@@ -40,6 +40,26 @@ def _substitute_yaml_values(runfiles_instance, obj, params):
   return obj
 
 
+# A list of message pieces that should be ignored even if logged by the test
+# server at a warning or an error severity.
+#
+# Other messages logged at either of these severities fail the test.
+_TEST_SERVER_WARN_ERROR_IGNORE_LIST = frozenset([
+    # TODO(#582): Identify these and file issues or add explanation as necessary.
+    "Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size",
+    "Using deprecated extension name 'envoy.listener.tls_inspector' for 'envoy.filters.listener.tls_inspector'.",
+    "there is no configured limit to the number of allowed active connections. Set a limit via the runtime key overload.global_downstream_max_connections",
+
+    # A few of our filters use the same typed configuration, specifically
+    # 'test-server', 'time-tracking' and 'dynamic-delay'.
+    # For now this is by design.
+    "Double registration for type: 'nighthawk.server.ResponseOptions'",
+
+    # Logged for normal termination, not really a warning.
+    "caught SIGTERM",
+])
+
+
 class TestServerBase(object):
   """Base class for running a server in a separate process.
 
@@ -126,6 +146,12 @@ def _serverThreadRunner(self):
     stdout, stderr = self._server_process.communicate()
     logging.info("Process stdout: %s", stdout.decode("utf-8"))
     logging.info("Process stderr: %s", stderr.decode("utf-8"))
+    warnings, errors = _extractWarningsAndErrors(stdout.decode() + stderr.decode(),
+                                                 _TEST_SERVER_WARN_ERROR_IGNORE_LIST)
+    if warnings:
+      [logging.warn("Process logged a warning: %s", w) for w in warnings]
+    if errors:
+      [logging.error("Process logged an error: %s", e) for e in errors]
 
   def fetchJsonFromAdminInterface(self, path):
     """Fetch and parse json from the admin interface.
@@ -253,3 +279,35 @@ def getCliVersionString(self):
     stdout, stderr = process.communicate()
     assert process.wait() == 0
     return stdout.decode("utf-8").strip()
+
+
+def _extractWarningsAndErrors(process_output, ignore_list):
+  """Extract warnings and errors from the process_output.
+
+  Args:
+    process_output: A string, the stdout or stderr after running a process.
+    ignore_list: A list of strings, message pieces to ignore. If a message that
+      was logged either at a warning or at an error severity contains one of
+      these message pieces, it will be excluded from the return values.
+
+  Returns:
+    A tuple of two lists of strings, the first list contains the warnings found
+    in the process_output and the second list contains the errors found in the
+    process_output.
+  """
+  warnings = []
+  errors = []
+  for line in process_output.split('\n'):
+    should_ignore = False
+    for ignore_message in ignore_list:
+      if ignore_message in line:
+        should_ignore = True
+        break
+    if should_ignore:
+      continue
+
+    if "[warning]" in line:
+      warnings.append(line)
+    elif "[error]" in line:
+      errors.append(line)
+  return warnings, errors

test/integration/unit_tests/BUILD

@@ -0,0 +1,11 @@
+load("@rules_python//python:defs.bzl", "py_binary", "py_library")
+
+licenses(["notice"])  # Apache 2
+
+py_test(
+    name = "test_nighthawk_test_server",
+    srcs = ["test_nighthawk_test_server.py"],
+    deps = [
+        "//test/integration:integration_test_base_lean",
+    ],
+)

test/integration/unit_tests/test_nighthawk_test_server.py

@@ -0,0 +1,70 @@
+"""Contains unit tests for functions in nighthawk_test_server.py."""
+
+import pytest
+
+from test.integration import nighthawk_test_server
+
+
+def test_extractWarningsAndErrors_nothing_on_empty_output():
+  """Test with an empty input."""
+  warnings, errors = nighthawk_test_server._extractWarningsAndErrors("", [])
+  assert not warnings
+  assert not errors
+
+
+def test_extractWarningsAndErrors_ignores_info_logs():
+  """Test where the process output doesn't contain any warnings or errors."""
+  process_output = """
+  [2020-12-01 04:41:57.219][126][info][misc] Message.
+  """
+  warnings, errors = nighthawk_test_server._extractWarningsAndErrors(process_output, [])
+  assert not warnings
+  assert not errors
+
+
+def test_extractWarningsAndErrors_extracts_a_warning():
+  """Test where the process output contains a single warning."""
+  process_output = "[2020-12-01 04:41:57.219][126][warning][misc] Message."
+  warnings, errors = nighthawk_test_server._extractWarningsAndErrors(process_output, [])
+  assert warnings == ["[2020-12-01 04:41:57.219][126][warning][misc] Message."]
+  assert not errors
+
+
+def test_extractWarningsAndErrors_extracts_an_error():
+  """Test where the process output contains a single error."""
+  process_output = "[2020-12-01 04:41:57.219][126][error][misc] Message."
+  warnings, errors = nighthawk_test_server._extractWarningsAndErrors(process_output, [])
+  assert not warnings
+  assert errors == ["[2020-12-01 04:41:57.219][126][error][misc] Message."]
+
+
+def test_extractWarningsAndErrors_extracts_multiple_messages():
+  """Test where the process output contains multiple warnings and errors."""
+  process_output = """[warning][misc] Warning1.
+[error][misc] Error1.
+[info][misc] Info1.
+[error][runtime] Error2.
+[warning][runtime] Warning2.
+  """
+  warnings, errors = nighthawk_test_server._extractWarningsAndErrors(process_output, [])
+  assert warnings == ["[warning][misc] Warning1.", "[warning][runtime] Warning2."]
+  assert errors == ["[error][misc] Error1.", "[error][runtime] Error2."]
+
+
+def test_extractWarningsAndErrors_skips_messages_matching_ignore_list():
+  """Test where the ignore list is used."""
+  process_output = """[warning][misc] Warning1 foo.
+[error][misc] Error1 bar.
+[info][misc] Info1.
+[error][runtime] Error2 baz.
+[warning][runtime] Warning2 bar.
+  """
+
+  ignore_list = ["foo", "bar"]
+  warnings, errors = nighthawk_test_server._extractWarningsAndErrors(process_output, ignore_list)
+  assert not warnings
+  assert errors == ["[error][runtime] Error2 baz."]
+
+
+if __name__ == "__main__":
+  raise SystemExit(pytest.main([__file__]))