Skip to content

add lwtracks for dsproxy get requests (#13916) #16774

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.

Sign up for GitHub

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
VPolka merged 1 commit into from
Apr 7, 2025
Merged

add lwtracks for dsproxy get requests (#13916) #16774

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
34 changes: 30 additions & 4 deletions ydb/core/blobstorage/dsproxy/dsproxy_get.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -130,6 +130,13 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor {
DiskCounters.resize(orderNumber + 1);
}
DiskCounters[orderNumber].Sent++;

LWTRACK(
DSProxyVGetSent, Orbit,
vDiskId.ToStringWOGeneration(),
orderNumber,
vGets.size()
);
}
for (size_t i = 0; i < vPuts.size(); ++i) {
if (RootCauseTrack.IsOn) {
Expand All @@ -143,6 +150,16 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor {
DiskCounters.resize(orderNumber + 1);
}
DiskCounters[orderNumber].Sent++;

LWTRACK(
DSProxyVPutSent, Orbit,
vPuts[i]->Type(),
vDiskId.ToStringWOGeneration(),
Info->GetFailDomainOrderNumber(vDiskId),
1,
vPuts[i]->GetBufferBytes(),
true
);
}
for (auto& ev : vGets) {
const ui64 cookie = ev->Record.GetCookie();
Expand Down Expand Up @@ -202,7 +219,7 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor {
const TVDiskID vdisk = VDiskIDFromVDiskID(record.GetVDiskID());
const TVDiskIdShort shortId(vdisk);

LWPROBE(DSProxyVDiskRequestDuration, TEvBlobStorage::EvVGet, totalSize, tabletId, vdisk.GroupID.GetRawId(), channel,
LWTRACK(DSProxyVDiskRequestDuration, Orbit, TEvBlobStorage::EvVGet, totalSize, tabletId, vdisk.GroupID.GetRawId(), channel,
Info->GetFailDomainOrderNumber(shortId),
GetStartTime(record.GetTimestamps()),
GetTotalTimeMs(record.GetTimestamps()),
Expand Down Expand Up @@ -285,7 +302,7 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor {

const TLogoBlobID blob = GetFirstBlobId(ev);
ui64 sumBlobSize = SumBlobSize(ev);
LWPROBE(DSProxyVDiskRequestDuration, TEvBlobStorage::EvVPut, sumBlobSize, blob.TabletID(),
LWTRACK(DSProxyVDiskRequestDuration, Orbit, TEvBlobStorage::EvVPut, sumBlobSize, blob.TabletID(),
Info->GroupID.GetRawId(), blob.Channel(), Info->GetFailDomainOrderNumber(shortId),
GetStartTime(record.GetTimestamps()),
GetTotalTimeMs(record.GetTimestamps()),
Expand Down Expand Up @@ -333,8 +350,9 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor {
TDuration timeToAccelerate = TDuration::MicroSeconds(timeToAccelerateUs);
TMonotonic now = TActivationContext::Monotonic();
TMonotonic nextAcceleration = RequestStartTime + timeToAccelerate;
LWTRACK(DSProxyScheduleAccelerate, Orbit, nextAcceleration > now ? (nextAcceleration - now).MicroSeconds() / 1000.0 : 0.0, "Get");
if (nextAcceleration > now) {
ui64 causeIdx = RootCauseTrack.RegisterAccelerate();
ui64 causeIdx = RootCauseTrack.RegisterAccelerate("Get");
Schedule(nextAcceleration - now, new TEvAccelerateGet(causeIdx));
IsGetAccelerateScheduled = true;
} else {
Expand All @@ -352,8 +370,9 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor {
TDuration timeToAccelerate = TDuration::MicroSeconds(timeToAccelerateUs);
TMonotonic now = TActivationContext::Monotonic();
TMonotonic nextAcceleration = RequestStartTime + timeToAccelerate;
LWTRACK(DSProxyScheduleAccelerate, Orbit, nextAcceleration > now ? (nextAcceleration - now).MicroSeconds() / 1000.0 : 0.0, "Put");
if (nextAcceleration > now) {
ui64 causeIdx = RootCauseTrack.RegisterAccelerate();
ui64 causeIdx = RootCauseTrack.RegisterAccelerate("Put");
Schedule(nextAcceleration - now, new TEvAcceleratePut(causeIdx));
IsPutAccelerateScheduled = true;
} else {
Expand Down Expand Up @@ -461,6 +480,13 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor {

LWTRACK(DSProxyGetBootstrap, Orbit);

LWTRACK(
DSProxyGetRequest, Orbit,
Info->GroupID.GetRawId(),
DeviceTypeStr(Info->GetDeviceType(), true),
NKikimrBlobStorage::EGetHandleClass_Name(GetImpl.GetHandleClass())
);

TDeque<std::unique_ptr<TEvBlobStorage::TEvVGet>> vGets;
TDeque<std::unique_ptr<TEvBlobStorage::TEvVPut>> vPuts;
GetImpl.GenerateInitialRequests(LogCtx, vGets);
Expand Down
4 changes: 2 additions & 2 deletions ydb/core/blobstorage/dsproxy/dsproxy_put.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -426,9 +426,9 @@ class TBlobStorageGroupPutRequest : public TBlobStorageGroupRequestActor {
TDuration timeToAccelerate = TDuration::MicroSeconds(timeToAccelerateUs);
TMonotonic now = TActivationContext::Monotonic();
TMonotonic nextAcceleration = RequestStartTime + timeToAccelerate;
LWTRACK(DSProxyScheduleAccelerate, Orbit, nextAcceleration > now ? (nextAcceleration - now).MicroSeconds() / 1000.0 : 0.0);
LWTRACK(DSProxyScheduleAccelerate, Orbit, nextAcceleration > now ? (nextAcceleration - now).MicroSeconds() / 1000.0 : 0.0, "Put");
if (nextAcceleration > now) {
ui64 causeIdx = RootCauseTrack.RegisterAccelerate();
ui64 causeIdx = RootCauseTrack.RegisterAccelerate("Put");
Schedule(nextAcceleration - now, new TEvAccelerate(causeIdx));
IsAccelerateScheduled = true;
} else {
Expand Down
13 changes: 8 additions & 5 deletions ydb/core/blobstorage/dsproxy/root_cause.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,13 +16,15 @@ struct TRootCause {
ui64 TransferCycles;
ui64 VDiskReplyCycles;
bool IsAccelerate;
TString RequestType;

TRootCauseItem(ui64 causeIdx, ui64 startCycles, bool isAccelerate)
TRootCauseItem(ui64 causeIdx, ui64 startCycles, bool isAccelerate, const TString& requestType)
: CauseIdx(causeIdx)
, StartCycles(startCycles)
, TransferCycles(startCycles)
, VDiskReplyCycles(startCycles)
, IsAccelerate(isAccelerate)
, RequestType(requestType)
{}
};
static constexpr ui64 InvalidCauseIdx = 255;
Expand All @@ -48,6 +50,7 @@ struct TRootCause {
}
NLWTrace::TParams params;
if (item.IsAccelerate) {
params.Param[1].CopyConstruct<TString>(item.RequestType);
orbit.AddProbe(&LWTRACE_GET_NAME(DSProxyScheduleAccelerate).Probe, params, item.StartCycles);
} else {
orbit.AddProbe(&LWTRACE_GET_NAME(DSProxyStartTransfer).Probe, params, item.StartCycles);
Expand All @@ -59,18 +62,18 @@ struct TRootCause {
#endif //LWTRACE_DISABLE
}

ui64 RegisterCause() {
ui64 RegisterCause(const TString& requestType = "") {
if (IsOn && Items.size() < InvalidCauseIdx - 1) {
Items.emplace_back(CurrentCauseIdx, GetCycleCountFast(), false);
Items.emplace_back(CurrentCauseIdx, GetCycleCountFast(), false, requestType);
return Items.size() - 1;
} else {
return InvalidCauseIdx;
}
}

ui64 RegisterAccelerate() {
ui64 RegisterAccelerate(const TString& requestType) {
if (IsOn && Items.size() < InvalidCauseIdx - 1) {
Items.emplace_back(CurrentCauseIdx, GetCycleCountFast(), true);
Items.emplace_back(CurrentCauseIdx, GetCycleCountFast(), true, requestType);
return Items.size() - 1;
} else {
return InvalidCauseIdx;
Expand Down
137 changes: 135 additions & 2 deletions ydb/core/blobstorage/dsproxy/ut/dsproxy_sequence_ut.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -651,7 +651,6 @@ Y_UNIT_TEST(TestGivenMirror3DCGetWithFirstSlowDisk) {

TTestState testState(runtime, type, DSProxyEnv.Info);


TEvBlobStorage::TEvGet::TPtr ev = testState.CreateGetRequest({blobId}, false);
TActorId getActorId = runtime.Register(DSProxyEnv.CreateGetRequestActor(ev, NKikimrBlobStorage::TabletLog).release());
runtime.EnableScheduleForActor(getActorId);
Expand Down Expand Up @@ -704,7 +703,6 @@ Y_UNIT_TEST(TestGivenBlock42GetThenVGetResponseParts2523Nodata4ThenGetOk) {
UNIT_ASSERT(getResult->Responses[0].Status == NKikimrProto::OK);
}


struct TBlobPack {
ui32 Count;
ui32 DataLength;
Expand Down Expand Up @@ -1285,6 +1283,141 @@ Y_UNIT_TEST(TestGivenBlock42Put6PartsOnOneVDiskWhenDiscoverThenRecoverFirst) {
}
}

Y_UNIT_TEST(TestBlock42CheckLwtrack) {
NLWTrace::TManager mngr(*Singleton<NLWTrace::TProbeRegistry>(), true);
NLWTrace::TOrbit orbit;
NLWTrace::TTraceRequest req;
req.SetIsTraced(true);
mngr.HandleTraceRequest(req, orbit);


TTestBasicRuntime runtime(1, false);
TBlobStorageGroupType type = {TErasureType::Erasure4Plus2Block};
Setup(runtime, type);
runtime.SetLogPriority(NKikimrServices::BS_PROXY_GET, NLog::PRI_DEBUG);

TActorId proxy = MakeBlobStorageProxyID(GROUP_ID);
TActorId sender = runtime.AllocateEdgeActor(0);

TString data("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx");
TLogoBlobID logoblobid(1, 0, 0, 0, (ui32)data.size(), 0);

TVector<TVDiskState> subgroup;
PrepareBlobSubgroup(logoblobid, data, subgroup, runtime, type);

auto ev = new TEvBlobStorage::TEvGet(logoblobid, 0, 0, TInstant::Max(),
NKikimrBlobStorage::EGetHandleClass::FastRead);
ev->Orbit = std::move(orbit);

runtime.Send(new IEventHandle(proxy, sender, ev));
for (ui32 i = 0; i < 6; ++i) {
TAutoPtr<IEventHandle> handle;
auto vget = runtime.GrabEdgeEventRethrow<TEvBlobStorage::TEvVGet>(handle);
UNIT_ASSERT(vget);
for (size_t idx = 0; idx < subgroup.size(); ++idx) {
if (subgroup[idx].ActorId == handle->Recipient) {
subgroup[idx].SetCookiesAndSenderFrom(handle.Get(), vget);
}
}
}

SendVGetResult(6, NKikimrProto::OK, 2, subgroup, runtime);
SendVGetResult(4, NKikimrProto::OK, 5, subgroup, runtime);
SendVGetResult(1, NKikimrProto::OK, 2, subgroup, runtime);
SendVGetResult(2, NKikimrProto::OK, 3, subgroup, runtime);
SendVGetResult(7, NKikimrProto::NODATA, 1, subgroup, runtime);
SendVGetResult(3, NKikimrProto::OK, 4, subgroup, runtime);
SendVGetResult(5, NKikimrProto::OK, 6, subgroup, runtime);
SendVGetResult(0, NKikimrProto::OK, 1, subgroup, runtime);

TAutoPtr<IEventHandle> handle;
auto getResult = runtime.GrabEdgeEventRethrow<TEvBlobStorage::TEvGetResult>(handle);
UNIT_ASSERT(getResult);
UNIT_ASSERT(getResult->Status == NKikimrProto::OK);
UNIT_ASSERT(getResult->ResponseSz == 1);
UNIT_ASSERT(getResult->Responses[0].Status == NKikimrProto::OK);

NLWTrace::TTraceResponse resp;
getResult->Orbit.Serialize(0, *resp.MutableTrace());
auto& r = resp.GetTrace();
UNIT_ASSERT_VALUES_EQUAL(21, r.EventsSize());

{
const auto& p = r.GetEvents(0);
UNIT_ASSERT_VALUES_EQUAL("BLOBSTORAGE_PROVIDER", p.GetProvider());
UNIT_ASSERT_VALUES_EQUAL("DSProxyGetHandle", p.GetName());
UNIT_ASSERT_VALUES_EQUAL(0 , p.ParamsSize());
}

{
const auto& p = r.GetEvents(1);
UNIT_ASSERT_VALUES_EQUAL("DSProxyGetBootstrap", p.GetName());
UNIT_ASSERT_VALUES_EQUAL(0 , p.ParamsSize());
}

{
const auto& p = r.GetEvents(2);
UNIT_ASSERT_VALUES_EQUAL("DSProxyGetRequest", p.GetName());
// check groupId
UNIT_ASSERT_VALUES_EQUAL(0, p.GetParams(0).GetUintValue());
// check deviceType
UNIT_ASSERT_VALUES_EQUAL("DEVICE_TYPE_UNKNOWN(255)", p.GetParams(1).GetStrValue());
// check handleClass
UNIT_ASSERT_VALUES_EQUAL("FastRead", p.GetParams(2).GetStrValue());
}

TVector<ui32> vdiskOrderNum = {0, 1, 4, 5, 6, 7};
for (auto i = 3; i < 9; ++i) {
const auto& p = r.GetEvents(i);
UNIT_ASSERT_VALUES_EQUAL("DSProxyVGetSent", p.GetName());
// check vdiskId
UNIT_ASSERT_VALUES_EQUAL("[0:_:0:" + ToString(vdiskOrderNum[i-3]) + ":0]", p.GetParams(0).GetStrValue());
// check vdiskOrderNum
UNIT_ASSERT_VALUES_EQUAL(vdiskOrderNum[i-3], p.GetParams(1).GetUintValue());
// check vgets count
UNIT_ASSERT_VALUES_EQUAL(6, p.GetParams(2).GetUintValue());
}

for (auto i = 9; i < 13; ++i) {
const auto& p = r.GetEvents(i);
UNIT_ASSERT_VALUES_EQUAL("DSProxyVDiskRequestDuration", p.GetName());
}

for (auto i = 13; i < 15; ++i) {
const auto& p = r.GetEvents(i);
UNIT_ASSERT_VALUES_EQUAL("DSProxyScheduleAccelerate", p.GetName());
UNIT_ASSERT_VALUES_EQUAL("Get", p.GetParams(1).GetStrValue());
}

for (auto i = 15; i < 17; ++i) {
const auto& p = r.GetEvents(i);
UNIT_ASSERT_VALUES_EQUAL("DSProxyVDiskRequestDuration", p.GetName());
}

{
const auto& p = r.GetEvents(17);
UNIT_ASSERT_VALUES_EQUAL("DSProxyStartTransfer", p.GetName());
UNIT_ASSERT_VALUES_EQUAL(0 , p.ParamsSize());
}

{
const auto& p = r.GetEvents(18);
UNIT_ASSERT_VALUES_EQUAL("VDiskStartProcessing", p.GetName());
UNIT_ASSERT_VALUES_EQUAL(0 , p.ParamsSize());
}

{
const auto& p = r.GetEvents(19);
UNIT_ASSERT_VALUES_EQUAL("VDiskReply", p.GetName());
UNIT_ASSERT_VALUES_EQUAL(0 , p.ParamsSize());
}

{
const auto& p = r.GetEvents(20);
UNIT_ASSERT_VALUES_EQUAL("DSProxyGetReply", p.GetName());
UNIT_ASSERT_VALUES_EQUAL(0 , p.ParamsSize());
}
}

} // Y_UNIT_TEST_SUITE TBlobStorageProxySequenceTest
} // namespace NBlobStorageProxySequenceTest
Expand Down
4 changes: 3 additions & 1 deletion ydb/core/blobstorage/lwtrace_probes/blobstorage_probes.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -284,6 +284,8 @@ struct TEventTypeField {
PROBE(DSProxyGetBootstrap, GROUPS("DSProxy"), TYPES(), NAMES()) \
PROBE(DSProxyGetHandle, GROUPS("DSProxy", "LWTrackStart"), TYPES(), NAMES()) \
PROBE(DSProxyGetReply, GROUPS("DSProxy"), TYPES(), NAMES()) \
PROBE(DSProxyVGetSent, GROUPS("DSProxy"), TYPES(TString, ui32, ui32), NAMES("vDiskId", "vdiskOrderNum", "count")) \
PROBE(DSProxyGetRequest, GROUPS("DSProxy", "LWTrackStart"), TYPES(ui32, TString, TString), NAMES("groupId", "deviceType", "handleClass")) \
PROBE(DSProxyPutEnqueue, GROUPS("DSProxy", "LWTrackStart"), TYPES(), NAMES()) \
PROBE(DSProxyPutHandle, GROUPS("DSProxyRequest", "DSProxy", "LWTrackStart"), TYPES(), NAMES()) \
PROBE(DSProxyPutBootstrapStart, GROUPS("DSProxy"), TYPES(), NAMES()) \
Expand All @@ -293,7 +295,7 @@ struct TEventTypeField {
PROBE(DSProxyPutReply, GROUPS("DSProxy"), TYPES(TString, TString, TString), NAMES("blobId", "status", "errorReason")) \
PROBE(DSProxyPutResumeBootstrap, GROUPS("DSProxy"), TYPES(), NAMES()) \
PROBE(DSProxyPutPauseBootstrap, GROUPS("DSProxy"), TYPES(), NAMES()) \
PROBE(DSProxyScheduleAccelerate, GROUPS("DSProxy"), TYPES(double), NAMES("timeBeforeAccelerationMs")) \
PROBE(DSProxyScheduleAccelerate, GROUPS("DSProxy"), TYPES(double, TString), NAMES("timeBeforeAccelerationMs", "reqType")) \
PROBE(DSProxyStartTransfer, GROUPS("DSProxy"), TYPES(), NAMES()) \
PROBE(VDiskStartProcessing, GROUPS("DSProxy"), TYPES(), NAMES()) \
PROBE(VDiskReply, GROUPS("DSProxy"), TYPES(), NAMES()) \
Expand Down
Loading