From 65411b8d4e57e1888ccdc1eb67f6350a832867c8 Mon Sep 17 00:00:00 2001 From: Hui Xiao Date: Fri, 17 Sep 2021 08:52:20 -0700 Subject: [PATCH] Improve rate_limiter_test.cc (#8904) Summary: - Fixed a bug in `RateLimiterTest.GeneratePriorityIterationOrder` that the callbacks in this test were not called starting from `i = 1`. Fix by increasing `rate_bytes_per_sec` and requested bytes. - The bug is due to the previous `rate_bytes_per_sec` was set too small, resulting in `refill_bytes_per_period` less than `kMinRefillBytesPerPeriod`. Hence the actual `refill_bytes_per_period` was equal to `kMinRefillBytesPerPeriod` due to the logic [here](https://github.com/facebook/rocksdb/blob/main/util/rate_limiter.cc#L302-L303) and it ended up being greater than the previously set requested bytes. Therefore starting from `i = 1`, `RefillBytesAndGrantRequests()` and `GeneratePriorityIterationOrder` won't be called and the test callbacks was not triggered to execute the assertion. - Added internal flag to assert callbacks are called in `RateLimiterTest.GeneratePriorityIterationOrder` to prevent any future changes defeat the purpose of the test [as suggested](https://github.com/facebook/rocksdb/pull/8890#discussion_r704915134) - Increased `rate_bytes_per_sec` and bytes of each request in `RateLimiterTest.GetTotalBytesThrough`, `RateLimiterTest.GetTotalRequests`, `RateLimiterTest.GetTotalPendingRequests` to trigger the "long path" of execution (i.e, the one trigger RefillBytesAndGrantRequests()) to increase test coverage - This increased the running time of the three tests, see test plan for time difference running locally - Cleared up sync point effects after each test by calling `SyncPoint::GetInstance()->DisableProcessing();` and `SyncPoint::GetInstance()->ClearAllCallBacks();` in `~RateLimiterTest()` [as suggested](https://github.com/facebook/rocksdb/pull/8595/files#r697534279) - It's fine to call these two methods even when `EnableProcessing()` or `SetCallBack()` is not called in the test or is already cleaned up. In those cases, calling these two functions in destructor is effectively no-op. - This will allow cleaning up sync point effects of previous test even when the previous test failed in assertion. - Added missing `SyncPoint::GetInstance()->DisableProcessing();` and `SyncPoint::GetInstance()->ClearCallBacks(..);` in existing tests for completeness - Called `SyncPoint::GetInstance()->DisableProcessing();` and `SyncPoint::GetInstance()->ClearCallBacks(..);` in loop in `RateLimiterTest.GeneratePriorityIterationOrder` for completeness Pull Request resolved: https://github.com/facebook/rocksdb/pull/8904 Test Plan: - Passing existing tests - To verify the 1st change, run `RateLimiterTest.GeneratePriorityIterationOrder` with assertions of callbacks are indeed called under original `rate_bytes_per_sec` and request byte and under updated `rate_bytes_per_sec` and request byte. The former will fail the assertion while the latter succeeds. - Here is the increased test time due to the 3rd change mentioned above in the summary. The relevant 3 tests mentioned in total increase the test time by 6s (~6000/33848 = 17.7% of the original total test time), which IMO is acceptable for better test coverage through running the "long path". - current (run on branch rate_limiter_ut_improve locally) [ RUN ] RateLimiterTest.GetTotalBytesThrough [ OK ] RateLimiterTest.GetTotalBytesThrough (3000 ms) [ RUN ] RateLimiterTest.GetTotalRequests [ OK ] RateLimiterTest.GetTotalRequests (3001 ms) [ RUN ] RateLimiterTest.GetTotalPendingRequests [ OK ] RateLimiterTest.GetTotalPendingRequests (0 ms) ... [----------] 10 tests from RateLimiterTest (43349 ms total) [----------] Global test environment tear-down [==========] 10 tests from 1 test case ran. (43349 ms total) [ PASSED ] 10 tests. - previous (run on branch main locally) [ RUN ] RateLimiterTest.GetTotalBytesThrough [ OK ] RateLimiterTest.GetTotalBytesThrough (0 ms) [ RUN ] RateLimiterTest.GetTotalRequests [ OK ] RateLimiterTest.GetTotalRequests (0 ms) [ RUN ] RateLimiterTest.GetTotalPendingRequests [ OK ] RateLimiterTest.GetTotalPendingRequests (0 ms) ... [----------] 10 tests from RateLimiterTest (33848 ms total) [----------] Global test environment tear-down [==========] 10 tests from 1 test case ran. (33848 ms total) [ PASSED ] 10 tests. Reviewed By: ajkr Differential Revision: D30872544 Pulled By: hx235 fbshipit-source-id: ff894f5c1a4bef70e8e407d53b00be45f776b3e4 --- util/rate_limiter_test.cc | 69 +++++++++++++++++++++++++-------------- 1 file changed, 44 insertions(+), 25 deletions(-) diff --git a/util/rate_limiter_test.cc b/util/rate_limiter_test.cc index cae82da34..f99394475 100644 --- a/util/rate_limiter_test.cc +++ b/util/rate_limiter_test.cc @@ -24,7 +24,13 @@ namespace ROCKSDB_NAMESPACE { // TODO(yhchiang): the rate will not be accurate when we run test in parallel. -class RateLimiterTest : public testing::Test {}; +class RateLimiterTest : public testing::Test { + protected: + ~RateLimiterTest() override { + SyncPoint::GetInstance()->DisableProcessing(); + SyncPoint::GetInstance()->ClearAllCallBacks(); + } +}; TEST_F(RateLimiterTest, OverflowRate) { GenericRateLimiter limiter(port::kMaxInt64, 1000, 10, @@ -39,14 +45,14 @@ TEST_F(RateLimiterTest, StartStop) { TEST_F(RateLimiterTest, GetTotalBytesThrough) { std::unique_ptr limiter(NewGenericRateLimiter( - 20 /* rate_bytes_per_sec */, 1000 * 1000 /* refill_period_us */, + 200 /* rate_bytes_per_sec */, 1000 * 1000 /* refill_period_us */, 10 /* fairness */)); for (int i = Env::IO_LOW; i <= Env::IO_TOTAL; ++i) { ASSERT_EQ(limiter->GetTotalBytesThrough(static_cast(i)), 0); } - std::int64_t request_byte = 10; + std::int64_t request_byte = 200; std::int64_t request_byte_sum = 0; for (int i = Env::IO_LOW; i < Env::IO_TOTAL; ++i) { limiter->Request(request_byte, static_cast(i), @@ -67,7 +73,7 @@ TEST_F(RateLimiterTest, GetTotalBytesThrough) { TEST_F(RateLimiterTest, GetTotalRequests) { std::unique_ptr limiter(NewGenericRateLimiter( - 20 /* rate_bytes_per_sec */, 1000 * 1000 /* refill_period_us */, + 200 /* rate_bytes_per_sec */, 1000 * 1000 /* refill_period_us */, 10 /* fairness */)); for (int i = Env::IO_LOW; i <= Env::IO_TOTAL; ++i) { ASSERT_EQ(limiter->GetTotalRequests(static_cast(i)), 0); @@ -75,7 +81,7 @@ TEST_F(RateLimiterTest, GetTotalRequests) { std::int64_t total_requests_sum = 0; for (int i = Env::IO_LOW; i < Env::IO_TOTAL; ++i) { - limiter->Request(10, static_cast(i), nullptr /* stats */, + limiter->Request(200, static_cast(i), nullptr /* stats */, RateLimiter::OpType::kWrite); total_requests_sum += 1; } @@ -91,15 +97,16 @@ TEST_F(RateLimiterTest, GetTotalRequests) { } TEST_F(RateLimiterTest, GetTotalPendingRequests) { - std::unique_ptr limiter( - NewGenericRateLimiter(20 /* rate_bytes_per_sec */)); + std::unique_ptr limiter(NewGenericRateLimiter( + 200 /* rate_bytes_per_sec */, 1000 * 1000 /* refill_period_us */, + 10 /* fairness */)); for (int i = Env::IO_LOW; i <= Env::IO_TOTAL; ++i) { ASSERT_EQ(limiter->GetTotalPendingRequests(static_cast(i)), 0); } // This is a variable for making sure the following callback is called // and the assertions in it are indeed excuted - bool nonzero_pending_requests_verified_ = false; + bool nonzero_pending_requests_verified = false; SyncPoint::GetInstance()->SetCallBack( "GenericRateLimiter::Request:PostEnqueueRequest", [&](void* arg) { port::Mutex* request_mutex = (port::Mutex*)arg; @@ -114,13 +121,13 @@ TEST_F(RateLimiterTest, GetTotalPendingRequests) { // We lock the mutex again so that the request thread can resume running // with the mutex locked request_mutex->Lock(); - nonzero_pending_requests_verified_ = true; + nonzero_pending_requests_verified = true; }); SyncPoint::GetInstance()->EnableProcessing(); - limiter->Request(20, Env::IO_USER, nullptr /* stats */, + limiter->Request(200, Env::IO_USER, nullptr /* stats */, RateLimiter::OpType::kWrite); - ASSERT_EQ(nonzero_pending_requests_verified_, true); + ASSERT_EQ(nonzero_pending_requests_verified, true); EXPECT_EQ(limiter->GetTotalPendingRequests(Env::IO_USER), 0); EXPECT_EQ(limiter->GetTotalPendingRequests(Env::IO_HIGH), 0); EXPECT_EQ(limiter->GetTotalPendingRequests(Env::IO_MID), 0); @@ -158,7 +165,7 @@ TEST_F(RateLimiterTest, Modes) { TEST_F(RateLimiterTest, GeneratePriorityIterationOrder) { std::unique_ptr limiter(NewGenericRateLimiter( - 20 /* rate_bytes_per_sec */, 1000 * 1000 /* refill_period_us */, + 200 /* rate_bytes_per_sec */, 1000 * 1000 /* refill_period_us */, 10 /* fairness */)); bool possible_random_one_in_fairness_results_for_high_mid_pri[4][2] = { @@ -170,6 +177,11 @@ TEST_F(RateLimiterTest, GeneratePriorityIterationOrder) { {Env::IO_USER, Env::IO_LOW, Env::IO_MID, Env::IO_HIGH}}; for (int i = 0; i < 4; ++i) { + // These are variables for making sure the following callbacks are called + // and the assertion in the last callback is indeed excuted + bool high_pri_iterated_after_mid_low_pri_set = false; + bool mid_pri_itereated_after_low_pri_set = false; + bool pri_iteration_order_verified = false; SyncPoint::GetInstance()->SetCallBack( "GenericRateLimiter::GeneratePriorityIterationOrder::" "PostRandomOneInFairnessForHighPri", @@ -177,6 +189,7 @@ TEST_F(RateLimiterTest, GeneratePriorityIterationOrder) { bool* high_pri_iterated_after_mid_low_pri = (bool*)arg; *high_pri_iterated_after_mid_low_pri = possible_random_one_in_fairness_results_for_high_mid_pri[i][0]; + high_pri_iterated_after_mid_low_pri_set = true; }); SyncPoint::GetInstance()->SetCallBack( @@ -186,6 +199,7 @@ TEST_F(RateLimiterTest, GeneratePriorityIterationOrder) { bool* mid_pri_itereated_after_low_pri = (bool*)arg; *mid_pri_itereated_after_low_pri = possible_random_one_in_fairness_results_for_high_mid_pri[i][1]; + mid_pri_itereated_after_low_pri_set = true; }); SyncPoint::GetInstance()->SetCallBack( @@ -201,28 +215,30 @@ TEST_F(RateLimiterTest, GeneratePriorityIterationOrder) { << ", mid_pri_itereated_after_low_pri = " << possible_random_one_in_fairness_results_for_high_mid_pri[i][1] << std::endl; + pri_iteration_order_verified = true; }); SyncPoint::GetInstance()->EnableProcessing(); - - limiter->Request(20 /* request max bytes to drain so that refill and order + limiter->Request(200 /* request max bytes to drain so that refill and order generation will be triggered every time GenericRateLimiter::Request() is called */ , Env::IO_USER, nullptr /* stats */, RateLimiter::OpType::kWrite); + ASSERT_EQ(high_pri_iterated_after_mid_low_pri_set, true); + ASSERT_EQ(mid_pri_itereated_after_low_pri_set, true); + ASSERT_EQ(pri_iteration_order_verified, true); + SyncPoint::GetInstance()->DisableProcessing(); + SyncPoint::GetInstance()->ClearCallBack( + "GenericRateLimiter::GeneratePriorityIterationOrder::" + "PreReturnPriIterationOrder"); + SyncPoint::GetInstance()->ClearCallBack( + "GenericRateLimiter::GeneratePriorityIterationOrder::" + "PostRandomOneInFairnessForMidPri"); + SyncPoint::GetInstance()->ClearCallBack( + "GenericRateLimiter::GeneratePriorityIterationOrder::" + "PostRandomOneInFairnessForHighPri"); } - - SyncPoint::GetInstance()->DisableProcessing(); - SyncPoint::GetInstance()->ClearCallBack( - "GenericRateLimiter::GeneratePriorityIterationOrder::" - "PreReturnPriIterationOrder"); - SyncPoint::GetInstance()->ClearCallBack( - "GenericRateLimiter::GeneratePriorityIterationOrder::" - "PostRandomOneInFairnessForMidPri"); - SyncPoint::GetInstance()->ClearCallBack( - "GenericRateLimiter::GeneratePriorityIterationOrder::" - "PostRandomOneInFairnessForHighPri"); } TEST_F(RateLimiterTest, Rate) { @@ -374,6 +390,7 @@ TEST_F(RateLimiterTest, LimitChangeTest) { target / 1024, new_limit / 1024, refill_period / 1000); } } + ROCKSDB_NAMESPACE::SyncPoint::GetInstance()->DisableProcessing(); } TEST_F(RateLimiterTest, AutoTuneIncreaseWhenFull) { @@ -413,6 +430,8 @@ TEST_F(RateLimiterTest, AutoTuneIncreaseWhenFull) { ASSERT_GT(new_bytes_per_sec, orig_bytes_per_sec); ROCKSDB_NAMESPACE::SyncPoint::GetInstance()->DisableProcessing(); + ROCKSDB_NAMESPACE::SyncPoint::GetInstance()->ClearCallBack( + "GenericRateLimiter::Request:PostTimedWait"); // decreases after a sequence of periods where rate limiter is not drained orig_bytes_per_sec = new_bytes_per_sec;