From 5c1834e8db46e2f402ad55b69fbfa5e03e6f68cc Mon Sep 17 00:00:00 2001 From: Donna Dionne Date: Wed, 6 Jan 2021 18:26:54 -0800 Subject: [PATCH] A previous fix which changed grpc_cycle_counter_to_millis_round_down/up was not the correct fix and caused window test issues. The correct fix is to ensure the test uses the same time apis as the product code: grp_get_cycle_counter (which is platform dependent) to get current time. Tested both in open source and patched into google3 to ensure successful import: https://critique-ng.corp.google.com/cl/349981071/analysis --- test/cpp/end2end/xds_end2end_test.cc | 54 ++++++++++++++-------------- 1 file changed, 28 insertions(+), 26 deletions(-) diff --git a/test/cpp/end2end/xds_end2end_test.cc b/test/cpp/end2end/xds_end2end_test.cc index 8ce46c59169..d408f345f48 100644 --- a/test/cpp/end2end/xds_end2end_test.cc +++ b/test/cpp/end2end/xds_end2end_test.cc @@ -54,6 +54,7 @@ #include "src/core/ext/xds/xds_client.h" #include "src/core/lib/channel/channel_args.h" #include "src/core/lib/gpr/env.h" +#include "src/core/lib/gpr/time_precise.h" #include "src/core/lib/gpr/tmpfile.h" #include "src/core/lib/gprpp/ref_counted_ptr.h" #include "src/core/lib/gprpp/sync.h" @@ -4463,11 +4464,9 @@ TEST_P(LdsRdsTest, XdsRoutingClusterUpdateClustersWithPickingDelays) { } TEST_P(LdsRdsTest, XdsRoutingApplyXdsTimeout) { - // TODO(https://github.com/grpc/grpc/issues/24549): TSAN won't work here. - if (BuiltUnderAsan() || BuiltUnderTsan()) return; - gpr_setenv("GRPC_XDS_EXPERIMENTAL_ENABLE_TIMEOUT", "true"); - const int64_t kTimeoutNano = 500000000; + const int64_t kTimeoutMillis = 500; + const int64_t kTimeoutNano = kTimeoutMillis * 1000000; const int64_t kTimeoutGrpcTimeoutHeaderMaxSecond = 1; const int64_t kTimeoutMaxStreamDurationSecond = 2; const int64_t kTimeoutHttpMaxStreamDurationSecond = 3; @@ -4557,7 +4556,11 @@ TEST_P(LdsRdsTest, XdsRoutingApplyXdsTimeout) { // Set listener and route config. SetListenerAndRouteConfiguration(0, std::move(listener), new_route_config); // Test grpc_timeout_header_max of 1.5 seconds applied - auto t0 = system_clock::now(); + gpr_cycle_counter now = gpr_get_cycle_counter(); + grpc_millis t0 = grpc_cycle_counter_to_millis_round_up(now); + grpc_millis t1 = + t0 + kTimeoutGrpcTimeoutHeaderMaxSecond * 1000 + kTimeoutMillis; + grpc_millis t2 = t0 + kTimeoutMaxStreamDurationSecond * 1000 + kTimeoutMillis; CheckRpcSendFailure(1, RpcOptions() .set_rpc_service(SERVICE_ECHO1) @@ -4565,15 +4568,15 @@ TEST_P(LdsRdsTest, XdsRoutingApplyXdsTimeout) { .set_wait_for_ready(true) .set_timeout_ms(kTimeoutApplicationSecond * 1000), StatusCode::DEADLINE_EXCEEDED); - auto ellapsed_nano_seconds = - std::chrono::duration_cast(system_clock::now() - - t0); - EXPECT_GT(ellapsed_nano_seconds.count(), - kTimeoutGrpcTimeoutHeaderMaxSecond * 1000000000 + kTimeoutNano); - EXPECT_LT(ellapsed_nano_seconds.count(), - kTimeoutMaxStreamDurationSecond * 1000000000); + now = gpr_get_cycle_counter(); + t0 = grpc_cycle_counter_to_millis_round_up(now); + EXPECT_GE(t0, t1); + EXPECT_LT(t0, t2); // Test max_stream_duration of 2.5 seconds applied - t0 = system_clock::now(); + now = gpr_get_cycle_counter(); + t0 = grpc_cycle_counter_to_millis_round_up(now); + t1 = t0 + kTimeoutMaxStreamDurationSecond * 1000 + kTimeoutMillis; + t2 = t0 + kTimeoutHttpMaxStreamDurationSecond * 1000 + kTimeoutMillis; CheckRpcSendFailure(1, RpcOptions() .set_rpc_service(SERVICE_ECHO2) @@ -4581,24 +4584,23 @@ TEST_P(LdsRdsTest, XdsRoutingApplyXdsTimeout) { .set_wait_for_ready(true) .set_timeout_ms(kTimeoutApplicationSecond * 1000), StatusCode::DEADLINE_EXCEEDED); - ellapsed_nano_seconds = std::chrono::duration_cast( - system_clock::now() - t0); - EXPECT_GT(ellapsed_nano_seconds.count(), - kTimeoutMaxStreamDurationSecond * 1000000000 + kTimeoutNano); - EXPECT_LT(ellapsed_nano_seconds.count(), - kTimeoutHttpMaxStreamDurationSecond * 1000000000); + now = gpr_get_cycle_counter(); + t0 = grpc_cycle_counter_to_millis_round_up(now); + EXPECT_GE(t0, t1); + EXPECT_LT(t0, t2); // Test http_stream_duration of 3.5 seconds applied - t0 = system_clock::now(); + now = gpr_get_cycle_counter(); + t0 = grpc_cycle_counter_to_millis_round_up(now); + t1 = t0 + kTimeoutHttpMaxStreamDurationSecond * 1000 + kTimeoutMillis; + t2 = t0 + kTimeoutApplicationSecond * 1000 + kTimeoutMillis; CheckRpcSendFailure(1, RpcOptions().set_wait_for_ready(true).set_timeout_ms( kTimeoutApplicationSecond * 1000), StatusCode::DEADLINE_EXCEEDED); - ellapsed_nano_seconds = std::chrono::duration_cast( - system_clock::now() - t0); - EXPECT_GT(ellapsed_nano_seconds.count(), - kTimeoutHttpMaxStreamDurationSecond * 1000000000 + kTimeoutNano); - EXPECT_LT(ellapsed_nano_seconds.count(), - kTimeoutApplicationSecond * 1000000000); + now = gpr_get_cycle_counter(); + t0 = grpc_cycle_counter_to_millis_round_up(now); + EXPECT_GE(t0, t1); + EXPECT_LT(t0, t2); gpr_unsetenv("GRPC_XDS_EXPERIMENTAL_ENABLE_TIMEOUT"); }