Skip to content

read rows rpc timeout logs #21504

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Jul 24, 2025
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
42 changes: 38 additions & 4 deletions ydb/core/grpc_services/rpc_read_rows.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -759,8 +759,38 @@ class TReadRowsRPC : public TActorBootstrapped<TReadRowsRPC> {
}

void HandleTimeout(TEvents::TEvWakeup::TPtr&) {
ReplyWithError(Ydb::StatusIds::TIMEOUT, TStringBuilder() << "ReadRows from table " << GetTable()
<< " timed out, duration: " << (TAppData::TimeProvider->Now() - StartTime).Seconds() << " sec");
TString errorMessage = TStringBuilder() << "ReadRows from table " << GetTable()
<< " timed out, duration: " << (TAppData::TimeProvider->Now() - StartTime).Seconds() << " sec\n";

auto errorLog = TStringBuilder() << "ShardIdToReadState: {";
ui64 rowsRequested = 0;
bool first = true;
for (const auto& [shardId, readState] : ShardIdToReadState) {
if (!first) {
errorLog << ", ";
}
first = false;
errorLog << "{"
<< " ShardId: " << shardId
<< " Status: " << readState.Status
<< " ContinuationToken: " << readState.FirstUnprocessedQuery
<< " }";

rowsRequested += readState.Keys.size();
}
errorLog << "}\n";

ui64 rowsRead = 0;
for (auto& result : EvReadResults) {
rowsRead += result->GetRowsCount();
}

errorLog << "ReadsInFlight: " << ReadsInFlight << '\n';
errorLog << "Retries: " << Retries << '\n';
errorLog << "Rows requested: " << rowsRequested << '\n';
errorLog << "Rows read: " << rowsRead << '\n';
errorLog << "Estimated RuCost: " << RuCost << '\n';
ReplyWithError(Ydb::StatusIds::TIMEOUT, errorMessage, nullptr, &errorLog);
}

void HandleForget(TRpcServices::TEvForgetOperation::TPtr& ev) {
Expand All @@ -771,10 +801,14 @@ class TReadRowsRPC : public TActorBootstrapped<TReadRowsRPC> {
}

void ReplyWithError(const Ydb::StatusIds::StatusCode& status, const TString& errorMsg,
const ::google::protobuf::RepeatedPtrField<Ydb::Issue::IssueMessage>* issues = nullptr)
const ::google::protobuf::RepeatedPtrField<Ydb::Issue::IssueMessage>* issues = nullptr, const TString* logAppendix = nullptr)
{
CancelReads();
LOG_ERROR_S(TlsActivationContext->AsActorContext(), NKikimrServices::RPC_REQUEST, "TReadRowsRPC ReplyWithError: " << errorMsg);
auto message = TStringBuilder() << "TReadRowsRPC ReplyWithError: " << errorMsg;
if (logAppendix) {
message << *logAppendix;
}
LOG_ERROR_S(TlsActivationContext->AsActorContext(), NKikimrServices::RPC_REQUEST, message);
SendResult(status, errorMsg, issues);
}

Expand Down
21 changes: 20 additions & 1 deletion ydb/services/ydb/ydb_read_rows_ut.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -92,8 +92,27 @@ Y_UNIT_TEST_SUITE(ReadRows) {
UNIT_ASSERT_VALUES_EQUAL(res.status(), ::Ydb::StatusIds::UNAVAILABLE);
}

}
dsReadResultOberver.Remove();


// Slow read
auto dsReadResultObserver = runtime.AddObserver<TEvDataShard::TEvReadResult>([&](auto&) {
SimulateSleep(runtime, TDuration::Seconds(100));
});

// Timeout
{
Ydb::Table::ReadRowsRequest request = MakeReadRowsRequest("/Root/table-1", {1, 5});
auto readRowsFuture = NRpcService::DoLocalRpc<TEvReadRowsRequest>(
std::move(request), "/Root", "", runtime.GetActorSystem(0));
auto res = runtime.WaitFuture(readRowsFuture, TDuration::Seconds(10));
UNIT_ASSERT_VALUES_EQUAL(res.status(), ::Ydb::StatusIds::TIMEOUT);
UNIT_ASSERT_VALUES_EQUAL(
res.issues().begin()->Getmessage(),
"ReadRows from table /Root/table-1 timed out, duration: 60 sec\n"
);
}
}
}

} // namespace NKikimr
Loading