Refactor Wilson Tracing in PDisk (#13406)

Author: va-kuznecov

ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp

@@ -17,8 +17,7 @@ namespace NPDisk {
 void TCompletionLogWrite::Exec(TActorSystem *actorSystem) {
     // bool isNewChunksCommited = false;
     if (CommitedLogChunks) {
-        NWilson::TSpan span(TWilson::PDiskBasic, TraceId.Clone(), "PDisk.CommitLogChunks");
-        auto* req = PDisk->ReqCreator.CreateFromArgs<TCommitLogChunks>(std::move(CommitedLogChunks), std::move(span));
+        auto* req = PDisk->ReqCreator.CreateFromArgs<TCommitLogChunks>(std::move(CommitedLogChunks));
         PDisk->InputRequest(req);
         //isNewChunksCommited = true;
     }
@@ -69,6 +68,7 @@ void TCompletionLogWrite::Exec(TActorSystem *actorSystem) {
             (*evLog.LogCallback)(actorSystem, *evLog.Result);
         }
         if (evLog.Result->Status == NKikimrProto::OK) {
+            evLog.Span.EndOk();
             if (batch) {
                 if (batch->Sender == evLog.Sender && batch->Result->Results.size() < MAX_RESULTS_PER_BATCH) {
                     batch->Result->Results.push_back(std::move(evLog.Result->Results[0]));
@@ -80,6 +80,7 @@ void TCompletionLogWrite::Exec(TActorSystem *actorSystem) {
                 batch = &evLog;
             }
         } else {
+            evLog.Span.EndError(evLog.Result->ErrorReason);
             // Send all previous successes...
             if (batch) {
                 sendResponse(batch);
@@ -115,8 +116,7 @@ void TCompletionLogWrite::Release(TActorSystem *actorSystem) {
 ////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
 
 TCompletionChunkReadPart::TCompletionChunkReadPart(TPDisk *pDisk, TIntrusivePtr<TChunkRead> &read, ui64 rawReadSize,
-        ui64 payloadReadSize, ui64 commonBufferOffset, TCompletionChunkRead *cumulativeCompletion, bool isTheLastPart,
-        NWilson::TSpan&& span)
+        ui64 payloadReadSize, ui64 commonBufferOffset, TCompletionChunkRead *cumulativeCompletion, bool isTheLastPart)
     : TCompletionAction()
     , PDisk(pDisk)
     , Read(read)
@@ -127,10 +127,14 @@ TCompletionChunkReadPart::TCompletionChunkReadPart(TPDisk *pDisk, TIntrusivePtr<
     , ChunkNonce(CumulativeCompletion->GetChunkNonce())
     , Buffer(PDisk->BufferPool->Pop())
     , IsTheLastPart(isTheLastPart)
-    , Span(std::move(span))
+    , Span(read->Span.CreateChild(TWilson::PDiskDetailed, "PDisk.ChunkRead.CompletionPart"))
 {
     TCompletionAction::CanBeExecutedInAdditionalCompletionThread = true;
 
+    Span.Attribute("common_buffer_offset", (i64)CommonBufferOffset)
+        .Attribute("raw_read_size", RawReadSize)
+        .Attribute("is_last_piece", IsTheLastPart);
+
     TBufferWithGaps *commonBuffer = CumulativeCompletion->GetCommonBuffer();
     Destination = commonBuffer->RawDataPtr(CommonBufferOffset, PayloadReadSize);
 
@@ -150,7 +154,6 @@ TBuffer *TCompletionChunkReadPart::GetBuffer() {
     return Buffer.Get();
 }
 
-
 void TCompletionChunkReadPart::UnencryptData(TActorSystem *actorSystem) {
     const TDiskFormat &format = PDisk->Format;
 
@@ -271,7 +274,6 @@ void TCompletionChunkReadPart::UnencryptData(TActorSystem *actorSystem) {
 }
 
 void TCompletionChunkReadPart::Exec(TActorSystem *actorSystem) {
-    auto execSpan = Span.CreateChild(TWilson::PDiskDetailed, "PDisk.CompletionChunkReadPart.Exec");
     Y_VERIFY(actorSystem);
     Y_VERIFY(CumulativeCompletion);
     if (TCompletionAction::Result != EIoResult::Ok) {
@@ -280,6 +282,7 @@ void TCompletionChunkReadPart::Exec(TActorSystem *actorSystem) {
     }
 
     if (Read->ChunkEncrypted) {
+        Span.Event("PDisk.CompletionChunkReadPart.DecryptionStart");
         UnencryptData(actorSystem);
     }
 
@@ -291,8 +294,7 @@ void TCompletionChunkReadPart::Exec(TActorSystem *actorSystem) {
 
     AtomicSub(PDisk->InFlightChunkRead, RawReadSize);
     RawReadSize = 0;
-    execSpan.EndOk();
-    Span.EndOk();
+    Span.Event("PDisk.CompletionChunkReadPart.ExecStop", {{"RawReadSize", RawReadSize}, {"EncryptedChunk", Read->ChunkEncrypted}});
     delete this;
 }
 
@@ -308,7 +310,7 @@ void TCompletionChunkReadPart::Release(TActorSystem *actorSystem) {
 }
 
 TCompletionChunkRead::TCompletionChunkRead(TPDisk *pDisk, TIntrusivePtr<TChunkRead> &read, std::function<void()> onDestroy,
-            ui64 chunkNonce, NWilson::TSpan&& span)
+            ui64 chunkNonce)
     : TCompletionAction()
     , PDisk(pDisk)
     , Read(read)
@@ -317,7 +319,7 @@ TCompletionChunkRead::TCompletionChunkRead(TPDisk *pDisk, TIntrusivePtr<TChunkRe
     , Deletes(0)
     , OnDestroy(std::move(onDestroy))
     , ChunkNonce(chunkNonce)
-    , Span(std::move(span))
+    , Span(read->Span.CreateChild(TWilson::PDiskBasic, "PDisk.CompletionChunkRead"))
     , DoubleFreeCanary(ReferenceCanary)
 {
     // in case of plain chunks we can have unaligned offset and unaligned size of the read
@@ -348,7 +350,7 @@ TCompletionChunkRead::~TCompletionChunkRead() {
 }
 
 void TCompletionChunkRead::Exec(TActorSystem *actorSystem) {
-    auto execSpan = Span.CreateChild(TWilson::PDiskDetailed, "PDisk.CompletionChunkRead.Exec");
+    Read->Span.Event("PDisk.CompletionChunkRead.Exec");
     THolder<TEvChunkReadResult> result = MakeHolder<TEvChunkReadResult>(NKikimrProto::OK,
         Read->ChunkIdx, Read->Offset, Read->Cookie, PDisk->GetStatusFlags(Read->Owner, Read->OwnerGroupType), "");
 
@@ -374,10 +376,9 @@ void TCompletionChunkRead::Exec(TActorSystem *actorSystem) {
 
     actorSystem->Send(Read->Sender, result.Release());
     Read->IsReplied = true;
+    Read->Span.EndOk();
 
     PDisk->Mon.GetReadCounter(Read->PriorityClass)->CountResponse();
-    execSpan.EndOk();
-    Span.EndOk();
     delete this;
 }
 
@@ -396,6 +397,7 @@ void TCompletionChunkRead::ReplyError(TActorSystem *actorSystem, TString reason)
     LOG_WARN_S(*actorSystem, NKikimrServices::BS_PDISK, error.Str());
     actorSystem->Send(Read->Sender, result.Release());
     Read->IsReplied = true;
+    Read->Span.EndError(reason);
 }
 
 // Returns true if there is some pending requests to wait
@@ -442,9 +444,7 @@ void TChunkTrimCompletion::Exec(TActorSystem *actorSystem) {
             << ui64(responseTimeMs) << " sizeBytes# " << SizeBytes);
     LWPROBE(PDiskTrimResponseTime, PDisk->PCtx->PDiskId, ReqId.Id, responseTimeMs, SizeBytes);
     PDisk->Mon.Trim.CountResponse();
-    NWilson::TSpan span(TWilson::PDiskBasic, std::move(TraceId), "PDisk.TryTrimChunk", NWilson::EFlags::AUTO_END, actorSystem);
-    span.Attribute("size", static_cast<i64>(SizeBytes));
-    TTryTrimChunk *tryTrim = PDisk->ReqCreator.CreateFromArgs<TTryTrimChunk>(SizeBytes, std::move(span));
+    TTryTrimChunk *tryTrim = PDisk->ReqCreator.CreateFromArgs<TTryTrimChunk>(SizeBytes);
     PDisk->InputRequest(tryTrim);
     delete this;
 }

ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h

@@ -83,8 +83,7 @@ class TCompletionChunkWrite : public TCompletionAction {
 
     TCompletionChunkWrite(const TActorId &recipient, TEvChunkWriteResult *event,
             TPDiskMon *mon, ui32 pdiskId, NHPTimer::STime startTime, size_t sizeBytes,
-            ui8 priorityClass, std::function<void()> onDestroy, TReqId reqId,
-            NWilson::TSpan&& span)
+            ui8 priorityClass, std::function<void()> onDestroy, TReqId reqId, NWilson::TSpan&& span)
         : Recipient(recipient)
         , Event(event)
         , Mon(mon)
@@ -147,7 +146,7 @@ class TCompletionChunkWrite : public TCompletionAction {
     }
 
     void Exec(TActorSystem *actorSystem) override {
-        auto execSpan = Span.CreateChild(TWilson::PDiskDetailed, "PDisk.CompletionChunkWrite.Exec");
+        Span.Event("PDisk.CompletionChunkWrite.Exec");
         double responseTimeMs = HPMilliSecondsFloat(HPNow() - StartTime);
         STLOGX(*actorSystem, PRI_DEBUG, BS_PDISK, BPD01, "TCompletionChunkWrite::Exec",
                 (DiskId, PDiskId),
@@ -165,8 +164,6 @@ class TCompletionChunkWrite : public TCompletionAction {
         if (Mon) {
             Mon->GetWriteCounter(PriorityClass)->CountResponse();
         }
-        execSpan.EndOk();
-        Span.EndOk();
         delete this;
     }
 
@@ -225,7 +222,7 @@ class TCompletionChunkRead : public TCompletionAction {
     const ui64 DoubleFreeCanary;
 public:
     TCompletionChunkRead(TPDisk *pDisk, TIntrusivePtr<TChunkRead> &read, std::function<void()> onDestroy,
-            ui64 chunkNonce, NWilson::TSpan&& span);
+            ui64 chunkNonce);
     void Exec(TActorSystem *actorSystem) override;
     ~TCompletionChunkRead();
     void ReplyError(TActorSystem *actorSystem, TString reason);
@@ -256,7 +253,7 @@ class TCompletionChunkRead : public TCompletionAction {
 
     void Release(TActorSystem *actorSystem) override {
         ReplyError(actorSystem, "TCompletionChunkRead is released");
-        Span.EndError("release");
+        Read->Span.EndError("TCompletionChunkRead is released");
     }
 };
 
@@ -274,8 +271,7 @@ class TCompletionChunkReadPart : public TCompletionAction {
     NWilson::TSpan Span;
 public:
     TCompletionChunkReadPart(TPDisk *pDisk, TIntrusivePtr<TChunkRead> &read, ui64 rawReadSize, ui64 payloadReadSize,
-            ui64 commonBufferOffset, TCompletionChunkRead *cumulativeCompletion, bool isTheLastPart,
-            NWilson::TSpan&& span);
+            ui64 commonBufferOffset, TCompletionChunkRead *cumulativeCompletion, bool isTheLastPart);
 
 
     bool CanHandleResult() const override {