Skip to content

Commit 9620972

Browse files
[BugFix] Abort BE vacuum tasks once the FE caller's timeout elapses
The FE gives up waiting for a vacuum RPC after its brpc timeout (1 hour), but the BE task keeps running as a zombie: it occupies one of the few RELEASE_SNAPSHOT workers and races with re-dispatched vacuums of the same partition for hours, while nobody reads its response. Carry the FE timeout in VacuumRequest.timeout_ms. The BE vacuum handler anchors an absolute deadline when the request is received and threads it through the vacuum execution; the version-chain walk checks the deadline on each iteration and aborts with Status::TimedOut once it passes. The check at vacuum entry also kills tasks that already exceeded the deadline while waiting in the thread pool queue. Requests from older FEs without the field carry no deadline and run to completion as before.
1 parent ca7d8bc commit 9620972

8 files changed

Lines changed: 213 additions & 9 deletions

File tree

be/src/service/service_be/lake_service.cpp

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1724,11 +1724,21 @@ void LakeServiceImpl::vacuum(::google::protobuf::RpcController* controller, cons
17241724

17251725
TEST_SYNC_POINT("LakeServiceImpl::vacuum:2");
17261726

1727+
// Anchor the deadline at the time the request is received: the FE caller waits at most
1728+
// |timeout_ms| from now, so once the deadline passes (whether the task waited in the
1729+
// thread pool queue or is in the middle of vacuuming) the task aborts itself instead of
1730+
// keeping a vacuum worker occupied for a response nobody reads. Requests without the
1731+
// field (older FE versions) carry no deadline and run to completion as before.
1732+
int64_t deadline_ms = 0;
1733+
if (request->has_timeout_ms() && request->timeout_ms() > 0) {
1734+
deadline_ms = butil::gettimeofday_ms() + request->timeout_ms();
1735+
}
1736+
17271737
auto latch = BThreadCountDownLatch(1);
17281738
auto task = std::make_shared<CancellableRunnable>(
17291739
[&] {
17301740
DeferOp defer([&] { latch.count_down(); });
1731-
lake::vacuum(_tablet_mgr, *request, response);
1741+
lake::vacuum(_tablet_mgr, *request, response, deadline_ms);
17321742
},
17331743
[&] {
17341744
Status st = Status::Cancelled("vacuum task has been cancelled");

be/src/storage/lake/vacuum.cpp

Lines changed: 33 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@
1717
#include <butil/fast_rand.h>
1818
#include <butil/time.h>
1919
#include <bvar/bvar.h>
20+
#include <fmt/format.h>
2021

2122
#include <optional>
2223
#include <set>
@@ -176,6 +177,25 @@ bool should_retry(const Status& st, int64_t attempted_retries) {
176177
return MatchPattern(message, config::lake_vacuum_retry_pattern.value());
177178
}
178179

180+
// Returns Status::TimedOut once |deadline_ms| (milliseconds since the Epoch) has passed.
181+
// deadline_ms <= 0 means no deadline. The deadline is anchored at the time the BE received
182+
// the vacuum request, so it also expires for tasks that waited too long in the thread pool
183+
// queue: by then the FE caller has given up waiting and would re-dispatch the partition,
184+
// continuing would only keep a vacuum worker occupied for a response nobody reads.
185+
Status check_vacuum_deadline(int64_t deadline_ms) {
186+
if (deadline_ms <= 0) {
187+
return Status::OK();
188+
}
189+
int64_t now_ms = butil::gettimeofday_ms();
190+
TEST_SYNC_POINT_CALLBACK("vacuum:check_deadline", &now_ms);
191+
if (now_ms >= deadline_ms) {
192+
return Status::TimedOut(
193+
fmt::format("vacuum task deadline exceeded, now={} deadline={}, the FE caller has given up waiting",
194+
now_ms, deadline_ms));
195+
}
196+
return Status::OK();
197+
}
198+
179199
Status delete_files_with_retry(FileSystem* fs, std::span<const std::string> paths) {
180200
const int64_t base = config::lake_vacuum_retry_min_delay_ms;
181201
const int64_t max_retries = config::lake_vacuum_retry_max_attempts;
@@ -417,7 +437,7 @@ static Status collect_files_to_vacuum(TabletManager* tablet_mgr, std::string_vie
417437
AsyncFileDeleter* datafile_deleter, AsyncFileDeleter* metafile_deleter,
418438
AsyncSharedFileDeleter* shared_file_deleter, int64_t* total_datafile_size,
419439
int64_t* vacuumed_version, int64_t* extra_datafile_size,
420-
const TabletRetainInfo& retain_info) {
440+
const TabletRetainInfo& retain_info, int64_t deadline_ms) {
421441
auto t0 = butil::gettimeofday_ms();
422442
auto meta_dir = join_path(root_dir, kMetadataDirectoryName);
423443
auto data_dir = join_path(root_dir, kSegmentDirectoryName);
@@ -437,6 +457,7 @@ static Status collect_files_to_vacuum(TabletManager* tablet_mgr, std::string_vie
437457
// Starting at |*final_retain_version|, read the tablet metadata forward along
438458
// the |prev_garbage_version| pointer until the tablet metadata does not exist.
439459
while (version >= min_version) {
460+
RETURN_IF_ERROR(check_vacuum_deadline(deadline_ms));
440461
// fill data cache to avoid read bundle meta file from remote storage repeatedly.
441462
auto res = tablet_mgr->get_tablet_metadata(
442463
tablet_id, version, false /* Not need to fill meta cache */,
@@ -557,7 +578,7 @@ static Status vacuum_tablet_metadata(TabletManager* tablet_mgr, std::string_view
557578
int64_t grace_timestamp, bool enable_file_bundling,
558579
bool enable_shared_file_cleanup, int64_t* vacuumed_files,
559580
int64_t* vacuumed_file_size, int64_t* vacuumed_version, int64_t* extra_file_size,
560-
const std::unordered_set<int64_t>& retain_versions) {
581+
const std::unordered_set<int64_t>& retain_versions, int64_t deadline_ms) {
561582
DCHECK(tablet_mgr != nullptr);
562583
DCHECK(std::is_sorted(tablet_infos.begin(), tablet_infos.end(),
563584
[](const auto& a, const auto& b) { return a.tablet_id() < b.tablet_id(); }));
@@ -586,7 +607,7 @@ static Status vacuum_tablet_metadata(TabletManager* tablet_mgr, std::string_view
586607
RETURN_IF_ERROR(collect_files_to_vacuum(tablet_mgr, root_dir, tablet_info, grace_timestamp, min_retain_version,
587608
vacuum_version_range.get(), &datafile_deleter, &metafile_deleter,
588609
&shared_file_deleter, vacuumed_file_size, &tablet_vacuumed_version,
589-
extra_file_size, tablet_retain_info));
610+
extra_file_size, tablet_retain_info, deadline_ms));
590611
RETURN_IF_ERROR(datafile_deleter.finish());
591612
(*vacuumed_files) += datafile_deleter.delete_count();
592613
if (!enable_file_bundling) {
@@ -795,7 +816,8 @@ Status vacuum_load_spill(std::string_view root_location, int64_t min_active_txn_
795816
return ret;
796817
}
797818

798-
Status vacuum_impl(TabletManager* tablet_mgr, const VacuumRequest& request, VacuumResponse* response) {
819+
Status vacuum_impl(TabletManager* tablet_mgr, const VacuumRequest& request, VacuumResponse* response,
820+
int64_t deadline_ms) {
799821
if (UNLIKELY(tablet_mgr == nullptr)) {
800822
return Status::InvalidArgument("tablet_mgr is null");
801823
}
@@ -808,6 +830,9 @@ Status vacuum_impl(TabletManager* tablet_mgr, const VacuumRequest& request, Vacu
808830
if (UNLIKELY(request.grace_timestamp() <= 0)) {
809831
return Status::InvalidArgument("value of grace_timestamp is zero or nagative");
810832
}
833+
// The task may have stayed in the thread pool queue long enough that the FE caller
834+
// already timed out and gave up, abort without doing any work in that case.
835+
RETURN_IF_ERROR(check_vacuum_deadline(deadline_ms));
811836

812837
auto tablet_infos = std::vector<TabletInfoPB>();
813838
if (request.tablet_infos_size() > 0) {
@@ -852,7 +877,8 @@ Status vacuum_impl(TabletManager* tablet_mgr, const VacuumRequest& request, Vacu
852877
request.has_enable_shared_file_cleanup() ? request.enable_shared_file_cleanup() : enable_file_bundling;
853878
RETURN_IF_ERROR(vacuum_tablet_metadata(tablet_mgr, root_loc, tablet_infos, min_retain_version, grace_timestamp,
854879
enable_file_bundling, enable_shared_file_cleanup, &vacuumed_files,
855-
&vacuumed_file_size, &vacuumed_version, &extra_file_size, retain_versions));
880+
&vacuumed_file_size, &vacuumed_version, &extra_file_size, retain_versions,
881+
deadline_ms));
856882
extra_file_size -= vacuumed_file_size;
857883
if (request.delete_txn_log()) {
858884
RETURN_IF_ERROR(vacuum_txn_log(root_loc, min_active_txn_id, &vacuumed_files, &vacuumed_file_size));
@@ -871,8 +897,8 @@ Status vacuum_impl(TabletManager* tablet_mgr, const VacuumRequest& request, Vacu
871897
return Status::OK();
872898
}
873899

874-
void vacuum(TabletManager* tablet_mgr, const VacuumRequest& request, VacuumResponse* response) {
875-
auto st = vacuum_impl(tablet_mgr, request, response);
900+
void vacuum(TabletManager* tablet_mgr, const VacuumRequest& request, VacuumResponse* response, int64_t deadline_ms) {
901+
auto st = vacuum_impl(tablet_mgr, request, response, deadline_ms);
876902
LOG_IF(ERROR, !st.ok()) << st;
877903
st.to_protobuf(response->mutable_status());
878904
}

be/src/storage/lake/vacuum.h

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,7 @@ namespace starrocks::lake {
3030

3131
class TabletManager;
3232

33-
void vacuum(TabletManager* tablet_mgr, const VacuumRequest& request, VacuumResponse* response);
33+
void vacuum(TabletManager* tablet_mgr, const VacuumRequest& request, VacuumResponse* response, int64_t deadline_ms = 0);
3434

3535
// REQUIRES:
3636
// - tablet_mgr != NULL

be/test/service/lake_service_test.cpp

Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4107,6 +4107,49 @@ TEST_F(LakeServiceTest, test_duplicated_vacuum_request) {
41074107
ASSERT_TRUE(duplicate);
41084108
}
41094109

4110+
TEST_F(LakeServiceTest, test_vacuum_task_deadline_exceeded) {
4111+
// Make every deadline check observe a clock far past the deadline. The callback only
4112+
// fires when the handler threads a positive deadline into the vacuum task, so this also
4113+
// guards against regressions where the handler stops passing the deadline down.
4114+
SyncPoint::GetInstance()->SetCallBack("vacuum:check_deadline",
4115+
[](void* arg) { *(int64_t*)arg = int64_t{1} << 62; });
4116+
SyncPoint::GetInstance()->EnableProcessing();
4117+
DeferOp defer([]() {
4118+
SyncPoint::GetInstance()->ClearCallBack("vacuum:check_deadline");
4119+
SyncPoint::GetInstance()->DisableProcessing();
4120+
});
4121+
4122+
{
4123+
// A request carrying timeout_ms aborts with TIMEOUT once the deadline passes.
4124+
brpc::Controller cntl;
4125+
VacuumRequest request;
4126+
VacuumResponse response;
4127+
request.add_tablet_ids(_tablet_id);
4128+
request.set_partition_id(next_id());
4129+
request.set_min_retain_version(1);
4130+
request.set_grace_timestamp(::time(nullptr));
4131+
request.set_timeout_ms(60 * 60 * 1000L);
4132+
_lake_service.vacuum(&cntl, &request, &response, nullptr);
4133+
EXPECT_FALSE(cntl.Failed()) << cntl.ErrorText();
4134+
ASSERT_EQ(TStatusCode::TIMEOUT, response.status().status_code()) << response.status().status_code();
4135+
}
4136+
4137+
{
4138+
// A request without timeout_ms (older FE versions) carries no deadline: even with the
4139+
// mocked clock the task runs to completion as before.
4140+
brpc::Controller cntl;
4141+
VacuumRequest request;
4142+
VacuumResponse response;
4143+
request.add_tablet_ids(_tablet_id);
4144+
request.set_partition_id(next_id());
4145+
request.set_min_retain_version(1);
4146+
request.set_grace_timestamp(::time(nullptr));
4147+
_lake_service.vacuum(&cntl, &request, &response, nullptr);
4148+
EXPECT_FALSE(cntl.Failed()) << cntl.ErrorText();
4149+
ASSERT_EQ(0, response.status().status_code()) << response.status().status_code();
4150+
}
4151+
}
4152+
41104153
TEST_F(LakeServiceTest, test_lock_and_unlock_tablet_metadata) {
41114154
{
41124155
LockTabletMetadataRequest request;

be/test/storage/lake/vacuum_test.cpp

Lines changed: 79 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3657,6 +3657,85 @@ TEST_P(LakeVacuumTest, full_vacuum_drops_local_cache_for_active_idx) {
36573657
EXPECT_NE(std::find(dropped.begin(), dropped.end(), std::string("8003_active.idx")), dropped.end());
36583658
}
36593659

3660+
// A deadline that expires while walking the version chain must stop the walk early without
3661+
// deleting anything; the next run (no deadline pressure) completes normally.
3662+
// NOLINTNEXTLINE
3663+
TEST_P(LakeVacuumTest, test_vacuum_deadline_expired_mid_walk) {
3664+
ASSERT_OK(_tablet_mgr->put_tablet_metadata(json_to_pb<TabletMetadataPB>(R"DEL(
3665+
{
3666+
"id": 20002,
3667+
"version": 2,
3668+
"prev_garbage_version": 0,
3669+
"commit_time": 1687331159
3670+
}
3671+
)DEL")));
3672+
ASSERT_OK(_tablet_mgr->put_tablet_metadata(json_to_pb<TabletMetadataPB>(R"DEL(
3673+
{
3674+
"id": 20002,
3675+
"version": 3,
3676+
"prev_garbage_version": 2,
3677+
"commit_time": 1687331160
3678+
}
3679+
)DEL")));
3680+
ASSERT_OK(_tablet_mgr->put_tablet_metadata(json_to_pb<TabletMetadataPB>(R"DEL(
3681+
{
3682+
"id": 20002,
3683+
"version": 4,
3684+
"prev_garbage_version": 3,
3685+
"commit_time": 1687331161
3686+
}
3687+
)DEL")));
3688+
3689+
// The first checks (request entry, first two walk iterations) observe a mocked clock
3690+
// before the deadline, every later check observes one far past it, so the deadline
3691+
// expires in the middle of the version chain walk.
3692+
int64_t check_count = 0;
3693+
SyncPoint::GetInstance()->SetCallBack("vacuum:check_deadline", [&](void* arg) {
3694+
check_count++;
3695+
*(int64_t*)arg = (check_count > 3) ? (int64_t{1} << 62) : 0;
3696+
});
3697+
SyncPoint::GetInstance()->EnableProcessing();
3698+
DeferOp defer([]() {
3699+
SyncPoint::GetInstance()->ClearCallBack("vacuum:check_deadline");
3700+
SyncPoint::GetInstance()->DisableProcessing();
3701+
});
3702+
3703+
{
3704+
VacuumRequest request;
3705+
VacuumResponse response;
3706+
request.add_tablet_ids(20002);
3707+
request.set_min_retain_version(4);
3708+
request.set_grace_timestamp(1687331162);
3709+
request.set_min_active_txn_id(12344);
3710+
vacuum(_tablet_mgr.get(), request, &response, /*deadline_ms=*/1);
3711+
ASSERT_TRUE(response.has_status());
3712+
EXPECT_EQ(TStatusCode::TIMEOUT, response.status().status_code()) << response.status().error_msgs(0);
3713+
EXPECT_GT(check_count, 3);
3714+
EXPECT_EQ(0, response.vacuumed_files());
3715+
EXPECT_TRUE(file_exist(tablet_metadata_filename(20002, 2)));
3716+
EXPECT_TRUE(file_exist(tablet_metadata_filename(20002, 3)));
3717+
EXPECT_TRUE(file_exist(tablet_metadata_filename(20002, 4)));
3718+
}
3719+
3720+
SyncPoint::GetInstance()->ClearCallBack("vacuum:check_deadline");
3721+
3722+
{
3723+
VacuumRequest request;
3724+
VacuumResponse response;
3725+
request.add_tablet_ids(20002);
3726+
request.set_min_retain_version(4);
3727+
request.set_grace_timestamp(1687331162);
3728+
request.set_min_active_txn_id(12344);
3729+
vacuum(_tablet_mgr.get(), request, &response);
3730+
ASSERT_TRUE(response.has_status());
3731+
EXPECT_EQ(0, response.status().status_code()) << response.status().error_msgs(0);
3732+
EXPECT_EQ(4, response.vacuumed_version());
3733+
EXPECT_FALSE(file_exist(tablet_metadata_filename(20002, 2)));
3734+
EXPECT_FALSE(file_exist(tablet_metadata_filename(20002, 3)));
3735+
EXPECT_TRUE(file_exist(tablet_metadata_filename(20002, 4)));
3736+
}
3737+
}
3738+
36603739
INSTANTIATE_TEST_SUITE_P(LakeVacuumTest, LakeVacuumTest,
36613740
::testing::Values(VacuumTestArg{1}, VacuumTestArg{3}, VacuumTestArg{100}));
36623741

fe/fe-core/src/main/java/com/starrocks/lake/vacuum/AutovacuumDaemon.java

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -318,6 +318,10 @@ private void vacuumPartitionImpl(Database db, OlapTable table, PhysicalPartition
318318
vacuumRequest.deleteTxnLog = needDeleteTxnLog;
319319
vacuumRequest.enableFileBundling = fileBundling;
320320
vacuumRequest.enableSharedFileCleanup = enableSharedFileCleanup;
321+
// The longest this FE waits for the response (the brpc timeout of the vacuum RPC).
322+
// The BE checks it periodically during execution and aborts the task once it has
323+
// elapsed, instead of running on as a zombie that no caller is waiting for.
324+
vacuumRequest.timeoutMs = LakeService.TIMEOUT_VACUUM;
321325
// Perform deletion of txn log on the first node only.
322326
needDeleteTxnLog = false;
323327
try {

fe/fe-core/src/test/java/com/starrocks/lake/VacuumTest.java

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,7 @@
5454
import org.junit.jupiter.api.Assertions;
5555
import org.junit.jupiter.api.BeforeAll;
5656
import org.junit.jupiter.api.Test;
57+
import org.mockito.ArgumentCaptor;
5758
import org.mockito.MockedStatic;
5859

5960
import java.util.ArrayList;
@@ -194,6 +195,43 @@ public void testLastSuccVacuumVersionUpdate() throws Exception {
194195
Assertions.assertEquals(0L, partition.getMetadataSwitchVersion());
195196
}
196197

198+
@Test
199+
public void testVacuumRequestCarriesTimeout() throws Exception {
200+
partition = olapTable.getPhysicalPartitions().stream().findFirst().orElse(null);
201+
partition.setVisibleVersion(10L, System.currentTimeMillis());
202+
partition.setMinRetainVersion(10L);
203+
partition.setLastSuccVacuumVersion(4L);
204+
205+
AutovacuumDaemon autovacuumDaemon = new AutovacuumDaemon();
206+
207+
VacuumResponse mockResponse = new VacuumResponse();
208+
mockResponse.status = new StatusPB();
209+
mockResponse.status.statusCode = 0;
210+
mockResponse.vacuumedFiles = 10L;
211+
mockResponse.vacuumedFileSize = 1024L;
212+
mockResponse.vacuumedVersion = 5L;
213+
mockResponse.extraFileSize = 1024L;
214+
mockResponse.tabletInfos = new ArrayList<>();
215+
216+
Future<VacuumResponse> mockFuture = mock(Future.class);
217+
when(mockFuture.get()).thenReturn(mockResponse);
218+
219+
lakeService = mock(LakeService.class);
220+
ArgumentCaptor<VacuumRequest> requestCaptor = ArgumentCaptor.forClass(VacuumRequest.class);
221+
when(lakeService.vacuum(requestCaptor.capture())).thenReturn(mockFuture);
222+
try (MockedStatic<BrpcProxy> mockBrpcProxyStatic = mockStatic(BrpcProxy.class)) {
223+
mockBrpcProxyStatic.when(() -> BrpcProxy.getLakeService(anyString(), anyInt())).thenReturn(lakeService);
224+
autovacuumDaemon.testVacuumPartitionImpl(db, olapTable, partition);
225+
}
226+
227+
Assertions.assertFalse(requestCaptor.getAllValues().isEmpty());
228+
for (VacuumRequest request : requestCaptor.getAllValues()) {
229+
// The BE aborts the vacuum task once this duration has elapsed, so it must match
230+
// the longest the FE actually waits, i.e. the brpc timeout of the vacuum RPC.
231+
Assertions.assertEquals(LakeService.TIMEOUT_VACUUM, (long) request.timeoutMs);
232+
}
233+
}
234+
197235
@Test
198236
public void testAggregateVacuum() throws Exception {
199237
GlobalStateMgr currentState = GlobalStateMgr.getCurrentState();

gensrc/proto/lake_service.proto

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -388,6 +388,10 @@ message VacuumRequest {
388388
// Whether enable shared file cleanup in vacuum.
389389
// This flag is used for both file-bundling tables and range-distribution tables.
390390
optional bool enable_shared_file_cleanup = 10;
391+
// The maximum duration the FE caller waits for this request, measured from the time
392+
// the request is received. After it elapses the FE has given up, so the BE task
393+
// should abort itself proactively instead of keeping a vacuum worker occupied.
394+
optional int64 timeout_ms = 11;
391395
}
392396

393397
message VacuumResponse {

0 commit comments

Comments
 (0)