tsan integration test flakes

[oschaaf]

Some of the end-to-end integration tests flake under ASAN/TSAN.
Pasting an example [1]:

It is hard to get the end-to-end tests stable when execution is slowed down to
an order of magnitude, as we cannot rely on simulated time like we do in the c++
tests.

Options that I can come up with to resolve:

• Loosen expectations for sanitizer-enabled runs of the integration tests. This would
  allow the sanitizers to still catch issues for the code that these tests hit.
• Allow tests to be retried a certain amount of time in santitizer-enabled runs
• Disable tests in sanitizer runs. This seems like a bad option: even though expectations
  aren't met, there is still value in the sanitizers observation of the code that gets hit (and
  any issues they observe).

[gw3] [ 41%] FAILED ../../../../../../../../../../../../../../../root/project/test/integration/test_integration_basics.py::test_https_h1_tls_context_configuration[IpVersion.IPV4] 

=================================== FAILURES ===================================
___________ test_https_h1_tls_context_configuration[IpVersion.IPV4] ____________
[gw3] linux -- Python 3.5.2 /usr/bin/python3

https_test_server_fixture = <test.integration.integration_test_fixtures.HttpsIntegrationTestBase object at 0x7fe1ccca6908>

    def test_https_h1_tls_context_configuration(https_test_server_fixture):
      """
      Verifies specifying tls cipher suites works with the h1 pool
      """
>     _do_tls_configuration_test(https_test_server_fixture, "--tls-context", use_h2=False)

https_test_server_fixture = <test.integration.integration_test_fixtures.HttpsIntegrationTestBase object at 0x7fe1ccca6908>

/root/project/test/integration/test_integration_basics.py:314: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/root/project/test/integration/test_integration_basics.py:307: in _do_tls_configuration_test
    assertCounterEqual(counters, "ssl.ciphers.%s" % cipher, 1)
test/integration/utility.py:35: in assertCounterEqual
    assertEqual(counters[name], value)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

a = 2, b = 1

    def assertEqual(a, b):
>     assert a == b
E     AssertionError

a          = 2
b          = 1

[mum4k]

It's not exactly clear from the paste as to what is causing the flaky behavior. Just the fact that execution is slowed shouldn't (ideally) cause flakiness.

If you have the context, can you add few more details on what is happening and we can discuss options together?

[oschaaf]

@mum4k the test fails on observing two ssl handshakes, instead of a single one.
So in the regular test, a single connection suffices and we pass. With the santizers
it looks like sometimes a second connection will be created, as the first one is still busy.
Arguably, this particular failure can be fixed by only allowing one single concurrent connection.
I'll create a PR for that.

Pasting another one that happened with the latest master merge, a timeout waiting
for the nighthawk grpc service to start:

=================================== FAILURES ===================================
_________________ test_grpc_service_happy_flow[IpVersion.IPV4] _________________
[gw3] linux -- Python 3.5.2 /usr/bin/python3

http_test_server_fixture = <integration_test_fixtures.HttpIntegrationTestBase object at 0x7f63450e9518>

    def test_grpc_service_happy_flow(http_test_server_fixture):
>     http_test_server_fixture.startNighthawkGrpcService("dummy-request-source")

http_test_server_fixture = <integration_test_fixtures.HttpIntegrationTestBase object at 0x7f63450e9518>

/root/project/test/integration/test_grpc_service.py:9: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <integration_test_fixtures.HttpIntegrationTestBase object at 0x7f63450e9518>
service_name = 'dummy-request-source'

    def startNighthawkGrpcService(self, service_name="traffic-generator-service"):
      host = self.server_ip if self.ip_version == IpVersion.IPV4 else "[%s]" % self.server_ip
      self.grpc_service = NighthawkGrpcService(
          os.path.join(self.test_rundir, "nighthawk_service"), host, self.ip_version, service_name)
>     assert (self.grpc_service.start())
E     AssertionError

host       = '127.0.0.1'
self       = <integration_test_fixtures.HttpIntegrationTestBase object at 0x7f63450e9518>
service_name = 'dummy-request-source'

/root/project/test/integration/integration_test_fixtures.py:224: AssertionError
------------------------------ Captured log call -------------------------------
ERROR    root:nighthawk_grpc_service.py:81 Timeout while waiting for server listener at 127.0.0.1:0 to accept connections.

[mum4k]

Thank you @oschaaf, how long is the timeout? Would the right call be to increase it to accommodate for the slowness with sanitizers?

[oschaaf]

I believe the current timeout is 15 seconds, I would expect that eventually the gRPC service
will come up, so bumping the timeout when running with the sanitizer should fix this.

[oschaaf]

Another one:

[gw0] [ 41%] FAILED ../../../../../../../../../../../../../../../root/project/test/integration/test_integration_basics.py::test_https_h2_multiple_connections[IpVersion.IPV4] 

=================================== FAILURES ===================================
______________ test_https_h2_multiple_connections[IpVersion.IPV4] ______________
[gw0] linux -- Python 3.6.9 /usr/bin/python3

https_test_server_fixture = <test.integration.integration_test_fixtures.HttpsIntegrationTestBase object at 0x7efdca5bd048>

    def test_https_h2_multiple_connections(https_test_server_fixture):
      """
      Test that the experimental h2 pool uses multiple connections.
      The burst we send ensures we will need 10 connections right away, as we
      limit max active streams per connection to 1 by setting the experimental
      flag to use multiple h2 connections.
      """
      parsed_json, _ = https_test_server_fixture.runNighthawkClient([
          "--h2",
          https_test_server_fixture.getTestServerRootUri(), "--rps", "100", "--duration", "100",
          "--termination-predicate", "benchmark.http_2xx:99", "--max-active-requests", "10",
          "--max-pending-requests", "10", "--experimental-h2-use-multiple-connections", "--burst-size",
          "10"
      ])
      counters = https_test_server_fixture.getNighthawkCounterMapFromJson(parsed_json)
>     assertCounterEqual(counters, "benchmark.http_2xx", 100)

The counter actually equaled 101

[oschaaf]

self assigned this:

I'm going to try and do some excessive repeated testing on my dev box with tsan enabled.
Hopefully that will tease out remaining tests that flake in sanitizer runs, so I can stabilize them.