From 38eb4160a977948f6d87916acd118a82797f7b0b Mon Sep 17 00:00:00 2001 From: Oleg Shatov <35371391+domwst@users.noreply.github.com> Date: Tue, 19 Dec 2023 18:59:59 +0600 Subject: [PATCH] KIKIMR-20042 Enchanced VDisk tracing (#571) * KIKIMR-20042 Enchanced VDisk tracing * Fix of TString creation --- .../vdisk/huge/blobstorage_hullhuge.cpp | 7 +++++-- ydb/core/blobstorage/vdisk/query/query_base.h | 17 +++++++++++++---- ydb/core/blobstorage/vdisk/query/query_extr.cpp | 15 +++++++++------ .../blobstorage/vdisk/query/query_range.cpp | 8 +++++--- .../blobstorage/vdisk/query/query_readactor.cpp | 2 ++ .../blobstorage/vdisk/query/query_readactor.h | 1 + .../vdisk/skeleton/blobstorage_skeleton.cpp | 2 +- 7 files changed, 36 insertions(+), 16 deletions(-) diff --git a/ydb/core/blobstorage/vdisk/huge/blobstorage_hullhuge.cpp b/ydb/core/blobstorage/vdisk/huge/blobstorage_hullhuge.cpp index 79acac7304ef..ed7c977cc4f0 100644 --- a/ydb/core/blobstorage/vdisk/huge/blobstorage_hullhuge.cpp +++ b/ydb/core/blobstorage/vdisk/huge/blobstorage_hullhuge.cpp @@ -198,7 +198,7 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); HugeKeeperCtx->PDiskCtx->Dsk->OwnerRound, chunkId, offset, partsPtr, Cookie, true, GetWritePriority(), false); ev->Orbit = std::move(Item->Orbit); - ctx.Send(HugeKeeperCtx->PDiskCtx->PDiskId, ev.release()); + ctx.Send(HugeKeeperCtx->PDiskCtx->PDiskId, ev.release(), 0, 0, Span.GetTraceId()); DiskAddr = TDiskPart(chunkId, offset, storedBlobSize); // wait response @@ -229,7 +229,10 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); CFunc(TEvents::TSystem::Poison, Die) ) - void HandlePoison(TEvents::TEvPoison::TPtr&, const TActorContext& ctx) { Die(ctx); } + void HandlePoison(TEvents::TEvPoison::TPtr&, const TActorContext& ctx) { + Span.EndError("EvPoison"); + Die(ctx); + } PDISK_TERMINATE_STATE_FUNC_DEF; public: diff --git a/ydb/core/blobstorage/vdisk/query/query_base.h b/ydb/core/blobstorage/vdisk/query/query_base.h index b8e6b237411f..04b370bef36b 100644 --- a/ydb/core/blobstorage/vdisk/query/query_base.h +++ b/ydb/core/blobstorage/vdisk/query/query_base.h @@ -5,6 +5,7 @@ #include "query_spacetracker.h" #include #include +#include namespace NKikimr { @@ -24,6 +25,8 @@ namespace NKikimr { TQueryResultSizeTracker ResultSize; const TActorId ReplSchedulerId; + NWilson::TSpan Span; + TLevelIndexQueryBase( std::shared_ptr &queryCtx, const TActorId &parentId, @@ -31,7 +34,8 @@ namespace NKikimr { TBarriersSnapshot &&barrierSnapshot, TEvBlobStorage::TEvVGet::TPtr &ev, std::unique_ptr result, - TActorId replSchedulerId) + TActorId replSchedulerId, + const char* name) : QueryCtx(queryCtx) , ParentId(parentId) , LogoBlobsSnapshot(std::move(logoBlobsSnapshot)) @@ -41,6 +45,7 @@ namespace NKikimr { , ShowInternals(Record.GetShowInternals()) , Result(std::move(result)) , ReplSchedulerId(replSchedulerId) + , Span(TWilson::VDiskTopLevel, std::move(BatcherCtx->OrigEv->TraceId), name) { Y_DEBUG_ABORT_UNLESS(Result); } @@ -87,11 +92,13 @@ namespace NKikimr { Result->AddResult(NKikimrProto::ERROR, id, &cookie); } } - LOG_CRIT(ctx, NKikimrServices::BS_VDISK_GET, - VDISKP(QueryCtx->HullCtx->VCtx->VDiskLogPrefix, + auto msg = VDISKP(QueryCtx->HullCtx->VCtx->VDiskLogPrefix, "TEvVGetResult: Result message is too large; size# %" PRIu64 " orig# %s;" " VDISK CAN NOT REPLY ON TEvVGet REQUEST", - ResultSize.GetSize(), BatcherCtx->OrigEv->Get()->ToString().data())); + ResultSize.GetSize(), BatcherCtx->OrigEv->Get()->ToString().data()); + LOG_CRIT(ctx, NKikimrServices::BS_VDISK_GET, msg); + + Span.EndError(std::move(msg)); } else { ui64 total = 0; for (const auto& result : Result->Record.GetResult()) { @@ -102,6 +109,8 @@ namespace NKikimr { LOG_DEBUG(ctx, NKikimrServices::BS_VDISK_GET, VDISKP(QueryCtx->HullCtx->VCtx->VDiskLogPrefix, "TEvVGetResult: %s", Result->ToString().data())); + + Span.EndOk(); } if (hasNotYet && ReplSchedulerId) { diff --git a/ydb/core/blobstorage/vdisk/query/query_extr.cpp b/ydb/core/blobstorage/vdisk/query/query_extr.cpp index 2d3f4d1f194c..0400a57a8624 100644 --- a/ydb/core/blobstorage/vdisk/query/query_extr.cpp +++ b/ydb/core/blobstorage/vdisk/query/query_extr.cpp @@ -78,9 +78,10 @@ namespace NKikimr { TBarriersSnapshot &&barrierSnapshot, TEvBlobStorage::TEvVGet::TPtr &ev, std::unique_ptr result, - TActorId replSchedulerId) + TActorId replSchedulerId, + const char* name) : TLevelIndexQueryBase(queryCtx, parentId, std::move(logoBlobsSnapshot), std::move(barrierSnapshot), - ev, std::move(result), replSchedulerId) + ev, std::move(result), replSchedulerId, name) {} }; @@ -161,7 +162,8 @@ namespace NKikimr { std::unique_ptr result, TActorId replSchedulerId) : TLevelIndexExtremeQueryViaBatcherBase(queryCtx, parentId, std::move(logoBlobsSnapshot), - std::move(barrierSnapshot), ev, std::move(result), replSchedulerId) + std::move(barrierSnapshot), ev, std::move(result), replSchedulerId, + "VDisk.LevelIndexExtremeQueryViaBatcherIndexOnly") , TActorBootstrapped() , Merger(QueryCtx->HullCtx->VCtx->Top->GType) {} @@ -367,8 +369,7 @@ namespace NKikimr { SendResponseAndDie(ctx, this); } else { ui8 priority = PDiskPriority(); - std::unique_ptr a(Batcher.CreateAsyncDataReader(ctx.SelfID, priority, /*std::move(Result->TraceId)*/ NWilson::TTraceId(), // FIXME: trace - IsRepl())); + std::unique_ptr a(Batcher.CreateAsyncDataReader(ctx.SelfID, priority, Span.GetTraceId(), IsRepl())); if (a) { auto aid = ctx.Register(a.release()); ActiveActors.Insert(aid, __FILE__, __LINE__, ctx, NKikimrServices::BLOBSTORAGE); @@ -385,6 +386,7 @@ namespace NKikimr { void HandlePoison(TEvents::TEvPoisonPill::TPtr &ev, const TActorContext &ctx) { Y_UNUSED(ev); ActiveActors.KillAndClear(ctx); + Span.EndError("TEvPoisonPill"); Die(ctx); } @@ -409,7 +411,8 @@ namespace NKikimr { std::unique_ptr result, TActorId replSchedulerId) : TLevelIndexExtremeQueryViaBatcherBase(queryCtx, parentId, std::move(logoBlobsSnapshot), - std::move(barrierSnapshot), ev, std::move(result), replSchedulerId) + std::move(barrierSnapshot), ev, std::move(result), replSchedulerId, + "VDisk.LevelIndexExtremeQueryViaBatcherMergeData") , TActorBootstrapped() , GType(QueryCtx->HullCtx->VCtx->Top->GType) , Batcher(BatcherCtx) diff --git a/ydb/core/blobstorage/vdisk/query/query_range.cpp b/ydb/core/blobstorage/vdisk/query/query_range.cpp index c2b76170fa66..aac3fa456461 100644 --- a/ydb/core/blobstorage/vdisk/query/query_range.cpp +++ b/ydb/core/blobstorage/vdisk/query/query_range.cpp @@ -57,9 +57,10 @@ namespace NKikimr { TBarriersSnapshot &&barriersSnapshot, TEvBlobStorage::TEvVGet::TPtr &ev, std::unique_ptr result, - TActorId replSchedulerId) + TActorId replSchedulerId, + const char* name) : TLevelIndexQueryBase(queryCtx, parentId, std::move(logoBlobsSnapshot), std::move(barriersSnapshot), - ev, std::move(result), replSchedulerId) + ev, std::move(result), replSchedulerId, name) , ForwardIt(QueryCtx->HullCtx, &LogoBlobsSnapshot) , BackwardIt(QueryCtx->HullCtx, &LogoBlobsSnapshot) , First() @@ -155,7 +156,8 @@ namespace NKikimr { std::unique_ptr result, TActorId replSchedulerId) : TLevelIndexRangeQueryViaBatcherBase(queryCtx, parentId, - std::move(logoBlobsSnapshot), std::move(barriersSnapshot), ev, std::move(result), replSchedulerId) + std::move(logoBlobsSnapshot), std::move(barriersSnapshot), ev, std::move(result), replSchedulerId, + "VDisk.LevelIndexRangeQueryViaBatcherBase") , TActorBootstrapped() , Merger(QueryCtx->HullCtx->VCtx->Top->GType) { diff --git a/ydb/core/blobstorage/vdisk/query/query_readactor.cpp b/ydb/core/blobstorage/vdisk/query/query_readactor.cpp index 93b8796fa06d..e6f5b08d88ba 100644 --- a/ydb/core/blobstorage/vdisk/query/query_readactor.cpp +++ b/ydb/core/blobstorage/vdisk/query/query_readactor.cpp @@ -60,6 +60,7 @@ namespace NKikimr { " origReadN# %" PRIu32, this, ui32(Result->GlueReads.size()), ui32(Result->DiskDataItemPtrs.size()))); ctx.Send(NotifyID, new TEvents::TEvCompleted); + Span.EndOk(); Die(ctx); } @@ -96,6 +97,7 @@ namespace NKikimr { void HandlePoison(TEvents::TEvPoisonPill::TPtr &ev, const TActorContext &ctx) { Y_UNUSED(ev); + Span.EndError("EvPoisonPill"); TThis::Die(ctx); } diff --git a/ydb/core/blobstorage/vdisk/query/query_readactor.h b/ydb/core/blobstorage/vdisk/query/query_readactor.h index 614625ee8b3f..9a32b196c985 100644 --- a/ydb/core/blobstorage/vdisk/query/query_readactor.h +++ b/ydb/core/blobstorage/vdisk/query/query_readactor.h @@ -1,5 +1,6 @@ #pragma once #include "defs.h" +#include namespace NKikimr { diff --git a/ydb/core/blobstorage/vdisk/skeleton/blobstorage_skeleton.cpp b/ydb/core/blobstorage/vdisk/skeleton/blobstorage_skeleton.cpp index 1d99a9fe5dd4..a197fe1a89b7 100644 --- a/ydb/core/blobstorage/vdisk/skeleton/blobstorage_skeleton.cpp +++ b/ydb/core/blobstorage/vdisk/skeleton/blobstorage_skeleton.cpp @@ -714,7 +714,7 @@ namespace NKikimr { if (!info.IsHugeBlob) { auto logMsg = CreatePutLogEvent(ctx, "TEvVPut", ev->Sender, ev->Cookie, std::move(ev->Get()->Orbit), info, std::move(result)); - ctx.Send(Db->LoggerID, logMsg.release()); + ctx.Send(Db->LoggerID, logMsg.release(), 0, 0, std::move(info.TraceId)); } else if (info.Buffer) { // pass the work to huge blob writer NKikimrBlobStorage::EPutHandleClass handleClass = record.GetHandleClass();