From 6675648344e83e8d98791e97f390c02fef604c23 Mon Sep 17 00:00:00 2001 From: Oleg Shatov Date: Mon, 8 Jan 2024 14:37:49 +0000 Subject: [PATCH 1/7] Enchanced VDisk & PDisk traces --- .../blobstorage_pdisk_completion_impl.cpp | 6 ++ .../pdisk/blobstorage_pdisk_completion_impl.h | 1 + .../pdisk/blobstorage_pdisk_impl.cpp | 63 ++++++++------ .../pdisk/blobstorage_pdisk_impl_log.cpp | 18 ++-- .../pdisk/blobstorage_pdisk_req_creator.h | 10 ++- .../pdisk/blobstorage_pdisk_requestimpl.cpp | 4 +- .../pdisk/blobstorage_pdisk_requestimpl.h | 35 +++++--- .../vdisk/huge/blobstorage_hullhuge.cpp | 27 ++++-- ydb/library/actors/wilson/wilson_span.h | 2 +- ydb/library/actors/wilson/wilson_span_stack.h | 84 +++++++++++++++++++ ydb/library/actors/wilson/wilson_with_span.h | 18 ++++ 11 files changed, 210 insertions(+), 58 deletions(-) create mode 100644 ydb/library/actors/wilson/wilson_span_stack.h create mode 100644 ydb/library/actors/wilson/wilson_with_span.h diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp index 9755aeff4b0a..2c0796fe6701 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp @@ -344,6 +344,12 @@ void TCompletionChunkRead::ReplyError(TActorSystem *actorSystem, TString reason) // Returns true if there is some pending requests to wait bool TCompletionChunkRead::PartReadComplete(TActorSystem *actorSystem) { TAtomicBase partsPending = AtomicDecrement(PartsPending); + { + TGuard lk(SpanStackLock); + if (auto span = Read->SpanStack.PeekTop()) { + span->Event("PartReadComplete"); + } + } if (partsPending == 0) { if (AtomicGet(Deletes) == 0) { Exec(actorSystem); diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h index c7dce8beea50..c303e2458fed 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h @@ -160,6 +160,7 @@ class TCompletionChunkRead : public TCompletionAction { TAtomic Deletes; std::function OnDestroy; ui64 ChunkNonce; + TMutex SpanStackLock; const ui64 DoubleFreeCanary; public: diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp index 463af890cf2a..7959c1b53a18 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp @@ -892,7 +892,7 @@ bool TPDisk::ChunkWritePiece(TChunkWrite *evChunkWrite, ui32 pieceShift, ui32 pi const ui32 count = evChunkWrite->PartsPtr->Size(); for (ui32 partIdx = evChunkWrite->CurrentPart; partIdx < count; ++partIdx) { ui32 remainingPartSize = (*evChunkWrite->PartsPtr)[partIdx].second - evChunkWrite->CurrentPartOffset; - auto traceId = evChunkWrite->Span.GetTraceId(); + auto traceId = evChunkWrite->SpanStack.GetTraceId(); if (bytesAvailable < remainingPartSize) { ui32 sizeToWrite = bytesAvailable; if (sizeToWrite > 0) { @@ -939,13 +939,13 @@ bool TPDisk::ChunkWritePiece(TChunkWrite *evChunkWrite, ui32 pieceShift, ui32 pi << " Marker# BPD79"); if (!writer.IsEmptySector()) { - auto traceId = evChunkWrite->Span.GetTraceId(); + auto traceId = evChunkWrite->SpanStack.GetTraceId(); *Mon.BandwidthPChunkPadding += writer.SectorBytesFree; writer.WriteZeroes(writer.SectorBytesFree, evChunkWrite->ReqId, &traceId); LOG_INFO(*ActorSystem, NKikimrServices::BS_PDISK, "PDiskId# %" PRIu32 " chunkIdx# %" PRIu32 " was zero-padded after writing", (ui32)PDiskId, (ui32)chunkIdx); } - auto traceId = evChunkWrite->Span.GetTraceId(); + auto traceId = evChunkWrite->SpanStack.GetTraceId(); evChunkWrite->Completion->Orbit = std::move(evChunkWrite->Orbit); writer.Flush(evChunkWrite->ReqId, &traceId, evChunkWrite->Completion.Release()); @@ -1056,7 +1056,7 @@ TPDisk::EChunkReadPieceResult TPDisk::ChunkReadPiece(TIntrusivePtr & completion->CostNs = DriveModel.TimeForSizeNs(bytesToRead, read->ChunkIdx, TDriveModel::OP_TYPE_READ); Y_ABORT_UNLESS(bytesToRead <= completion->GetBuffer()->Size()); ui8 *data = completion->GetBuffer()->Data(); - auto traceId = read->Span.GetTraceId(); + auto traceId = read->SpanStack.GetTraceId(); BlockDevice->PreadAsync(data, bytesToRead, readOffset, completion.Release(), read->ReqId, &traceId); // TODO: align the data on SectorSize, not PAGE_SIZE @@ -1350,7 +1350,7 @@ TVector TPDisk::AllocateChunkForOwner(const TRequestBase *req, const for (TChunkIdx chunkIdx : chunks) { ui64 chunkNonce = SysLogRecord.Nonces.Value[NonceData]; SysLogRecord.Nonces.Value[NonceData] += dataChunkSizeSectors; - auto traceId = req->Span.GetTraceId(); + auto traceId = req->SpanStack.GetTraceId(); OnNonceChange(NonceData, req->ReqId, &traceId); // Remember who owns the sector, save chunk Nonce in order to be able to continue writing the chunk TChunkState &state = ChunkState[chunkIdx]; @@ -2246,6 +2246,8 @@ void TPDisk::ProcessChunkWriteQueue() { NHPTimer::STime now = HPNow(); for (auto it = JointChunkWrites.begin(); it != JointChunkWrites.end(); ++it) { TRequestBase *req = (*it); + req->SpanStack.PopOk(); + req->SpanStack.Push(TWilson::PDisk, "PDisk.InBlockDevice", NWilson::EFlags::AUTO_END); switch (req->GetType()) { case ERequestType::RequestChunkWritePiece: { @@ -2275,6 +2277,8 @@ void TPDisk::ProcessChunkReadQueue() { for (auto& req : JointChunkReads) { + req->SpanStack.PopOk(); + req->SpanStack.Push(TWilson::PDisk, "PDisk.InBlockDevice", NWilson::EFlags::AUTO_END); switch (req->GetType()) { case ERequestType::RequestChunkReadPiece: { @@ -2345,6 +2349,8 @@ void TPDisk::ProcessChunkTrimQueue() { Y_ABORT_UNLESS(JointChunkTrims.size() <= 1); for (auto it = JointChunkTrims.begin(); it != JointChunkTrims.end(); ++it) { TChunkTrim *trim = (*it); + trim->SpanStack.PopOk(); + trim->SpanStack.Push(TWilson::PDisk, "PDisk.InBlockDevice", NWilson::EFlags::AUTO_END); ui64 chunkOffset = Format.ChunkSize * ui64(trim->ChunkIdx); ui64 offset = chunkOffset + trim->Offset; ui64 trimSize = trim->Size; @@ -2501,7 +2507,7 @@ void TPDisk::ProcessFastOperationsQueue() { OnLogCommitDone(static_cast(*req)); break; case ERequestType::RequestTryTrimChunk: - TryTrimChunk(true, static_cast(*req).TrimSize, req->Span); + TryTrimChunk(true, static_cast(*req).TrimSize, req->SpanStack.PeekTop() ? *req->SpanStack.PeekTop() : static_cast(NWilson::TSpan{})); break; case ERequestType::RequestReleaseChunks: MarkChunksAsReleased(static_cast(*req)); @@ -2519,6 +2525,7 @@ void TPDisk::ProcessChunkForgetQueue() { return; for (auto& req : JointChunkForgets) { + req->SpanStack.PopOk(); ChunkForget(*req); } @@ -2751,7 +2758,7 @@ void TPDisk::PrepareLogError(TLogWrite *logWrite, TStringStream& err, NKikimrPro << " lsn# " << logWrite->Lsn; LOG_ERROR_S(*ActorSystem, NKikimrServices::BS_PDISK, err.Str()); - logWrite->Span.EndError(err.Str()); + logWrite->SpanStack.PopError(err.Str()); logWrite->Result.Reset(new NPDisk::TEvLogResult(status, GetStatusFlags(logWrite->Owner, logWrite->OwnerGroupType), err.Str())); logWrite->Result->Results.push_back(NPDisk::TEvLogResult::TRecord(logWrite->Lsn, logWrite->Cookie)); @@ -3121,7 +3128,6 @@ bool TPDisk::PreprocessRequest(TRequestBase *request) { } void TPDisk::PushRequestToForseti(TRequestBase *request) { - request->Span.Event("PushToForseti", {}); if (request->GateId != GateFastOperation) { bool isAdded = false; @@ -3160,9 +3166,9 @@ void TPDisk::PushRequestToForseti(TRequestBase *request) { && static_cast(job->Payload)->GetType() == ERequestType::RequestLogWrite) { TLogWrite &batch = *static_cast(job->Payload); - request->Span.Event("AddToBatch", NWilson::TKeyValueList{{ - { "Batch.ReqId", static_cast(batch.ReqId.Id) }, - }}); + if (auto span = request->SpanStack.Push(TWilson::PDisk, "PDisk.InForseti.InBatch")) { + span->Attribute("Batch.ReqId", static_cast(batch.ReqId.Id)); + } batch.AddToBatch(static_cast(request)); ui64 prevCost = job->Cost; job->Cost += request->Cost; @@ -3186,7 +3192,7 @@ void TPDisk::PushRequestToForseti(TRequestBase *request) { SplitChunkJobSize(whole->TotalSize, &smallJobSize, &largeJobSize, &smallJobCount); for (ui32 idx = 0; idx < smallJobCount; ++idx) { // Schedule small job. - auto span = request->Span.CreateChild(TWilson::PDisk, "PDisk.ChunkWritePiece", NWilson::EFlags::AUTO_END); + auto span = request->SpanStack.CreateChild(TWilson::PDisk, "PDisk.ChunkWritePiece", NWilson::EFlags::AUTO_END); span.Attribute("small_job_idx", idx) .Attribute("is_last_piece", false); TChunkWritePiece *piece = new TChunkWritePiece(whole, idx * smallJobSize, smallJobSize, std::move(span)); @@ -3194,7 +3200,7 @@ void TPDisk::PushRequestToForseti(TRequestBase *request) { AddJobToForseti(cbs, piece, request->JobKind); } // Schedule large job (there always is one) - auto span = request->Span.CreateChild(TWilson::PDisk, "PDisk.ChunkWritePiece", NWilson::EFlags::AUTO_END); + auto span = request->SpanStack.CreateChild(TWilson::PDisk, "PDisk.ChunkWritePiece", NWilson::EFlags::AUTO_END); span.Attribute("is_last_piece", true); TChunkWritePiece *piece = new TChunkWritePiece(whole, smallJobCount * smallJobSize, largeJobSize, std::move(span)); piece->EstimateCost(DriveModel); @@ -3214,7 +3220,7 @@ void TPDisk::PushRequestToForseti(TRequestBase *request) { ui32 largeJobSize = totalSectors - smallJobSize * smallJobCount; for (ui32 idx = 0; idx < smallJobCount; ++idx) { - auto span = request->Span.CreateChild(TWilson::PDisk, "PDisk.ChunkReadPiece", NWilson::EFlags::AUTO_END); + auto span = request->SpanStack.CreateChild(TWilson::PDisk, "PDisk.ChunkReadPiece", NWilson::EFlags::AUTO_END); span.Attribute("small_job_idx", idx) .Attribute("is_last_piece", false); // Schedule small job. @@ -3227,8 +3233,7 @@ void TPDisk::PushRequestToForseti(TRequestBase *request) { AddJobToForseti(cbs, piece, request->JobKind); } // Schedule large job (there always is one) - NWilson::TSpan span(TWilson::PDisk, request->Span.GetTraceId(), - "PDisk.ChunkReadPiece", NWilson::EFlags::NONE, request->Span.GetActorSystem()); + auto span = request->SpanStack.CreateChild(TWilson::PDisk, "PDisk.ChunkReadPiece"); span.Attribute("is_last_piece", true); auto piece = new TChunkReadPiece(read, smallJobCount * smallJobSize, largeJobSize * Format.SectorSize, true, std::move(span)); @@ -3243,7 +3248,6 @@ void TPDisk::PushRequestToForseti(TRequestBase *request) { } } } else { - request->Span.Event("PushToFastOperationsQueue", {}); FastOperationsQueue.push_back(std::unique_ptr(request)); LOG_DEBUG(*ActorSystem, NKikimrServices::BS_PDISK, "PDiskId# %" PRIu32 " ReqId# %" PRIu64 " PushRequestToForseti Push to FastOperationsQueue.size# %" PRIu64, @@ -3265,6 +3269,7 @@ void TPDisk::SplitChunkJobSize(ui32 totalSize, ui32 *outSmallJobSize, ui32 *outL void TPDisk::AddJobToForseti(NSchLab::TCbs *cbs, TRequestBase *request, NSchLab::EJobKind jobKind) { LWTRACK(PDiskAddToScheduler, request->Orbit, PDiskId, request->ReqId.Id, HPSecondsFloat(request->CreationTime), request->Owner, request->IsFast, request->PriorityClass); + request->SpanStack.Push(TWilson::PDisk, "PDisk.InForseti"); TIntrusivePtr job = ForsetiScheduler.CreateJob(); job->Payload = request; job->Cost = request->Cost; @@ -3291,25 +3296,29 @@ void TPDisk::RouteRequest(TRequestBase *request) { case ERequestType::RequestLogReadResultProcess: [[fallthrough]]; case ERequestType::RequestLogSectorRestore: - request->Span.Event("PushToJointLogReads", {}); + request->SpanStack.PopOk(); + request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointLogReads"); JointLogReads.push_back(request); break; case ERequestType::RequestChunkReadPiece: { TChunkReadPiece *piece = static_cast(request); - request->Span.Event("PushToJointChunkReads", {}); + request->SpanStack.PopOk(); + request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointChunkReads"); JointChunkReads.emplace_back(piece->SelfPointer.Get()); piece->SelfPointer.Reset(); // FIXME(cthulhu): Unreserve() for TChunkReadPiece is called while processing to avoid requeueing issues break; } case ERequestType::RequestChunkWritePiece: - request->Span.Event("PushToJointChunkWrites", {}); + request->SpanStack.PopOk(); + request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointChunkWrites"); JointChunkWrites.push_back(request); break; case ERequestType::RequestChunkTrim: { - request->Span.Event("PushToJointChunkTrims", {}); + request->SpanStack.PopOk(); + request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointChunkTrims"); TChunkTrim *trim = static_cast(request); JointChunkTrims.push_back(trim); break; @@ -3320,10 +3329,12 @@ void TPDisk::RouteRequest(TRequestBase *request) { while (log) { TLogWrite *batch = log->PopFromBatch(); - log->Span.Event("PushToJointLogWrites", {}); + log->SpanStack.PopOk(); + if (auto span = log->SpanStack.Push(TWilson::PDisk, "PDisk.InJointLogWrites")) { + span->Attribute("HasCommitRecord", log->Signature.HasCommitRecord()); + } JointLogWrites.push_back(log); if (log->Signature.HasCommitRecord()) { - log->Span.Event("PushToJointCommits", {}); JointCommits.push_back(log); } log = batch; @@ -3332,7 +3343,8 @@ void TPDisk::RouteRequest(TRequestBase *request) { } case ERequestType::RequestChunkForget: { - request->Span.Event("PushToJointChunkForgets", {}); + request->SpanStack.PopOk(); + request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointChunkForgets"); TChunkForget *forget = static_cast(request); JointChunkForgets.push_back(std::unique_ptr(forget)); break; @@ -3423,11 +3435,9 @@ void TPDisk::EnqueueAll() { TYardControl &evControl = *static_cast(request); switch (evControl.Action) { case NPDisk::TEvYardControl::ActionPause: - request->Span.Event("PushToPausedQueue", {}); PausedQueue.push_back(request); break; case NPDisk::TEvYardControl::ActionStep: - request->Span.Event("PushToPausedQueue", {}); PausedQueue.push_back(request); ActorSystem->Send(evControl.Sender, new NPDisk::TEvYardControlResult( NKikimrProto::OK, evControl.Cookie, TString())); @@ -3448,7 +3458,6 @@ void TPDisk::EnqueueAll() { break; } } else { - request->Span.Event("PushToPausedQueue", {}); PausedQueue.push_back(request); } } else { diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl_log.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl_log.cpp index 31d4e3684d7b..ad5cc3d91e6f 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl_log.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl_log.cpp @@ -533,6 +533,8 @@ void TPDisk::ReadAndParseMainLog(const TActorId &pDiskActor) { void TPDisk::ProcessLogReadQueue() { for (auto& req : JointLogReads) { + req->SpanStack.PopOk(); + req->SpanStack.Push(TWilson::PDisk, "PDisk.InBlockDevice", NWilson::EFlags::AUTO_END); switch (req->GetType()) { case ERequestType::RequestLogRead: { @@ -592,7 +594,7 @@ void TPDisk::ProcessLogReadQueue() { TLogReadContinue *read = static_cast(req); read->CompletionAction->CostNs = DriveModel.TimeForSizeNs(read->Size, read->Offset / Format.ChunkSize, TDriveModel::OP_TYPE_READ); - auto traceId = read->Span.GetTraceId(); + auto traceId = read->SpanStack.GetTraceId(); BlockDevice->PreadAsync(read->Data, read->Size, read->Offset, read->CompletionAction, read->ReqId, &traceId); // ??? TraceId break; @@ -728,14 +730,16 @@ void TPDisk::ProcessLogWriteQueueAndCommits() { TVector logChunksToCommit; for (TLogWrite *logWrite : JointLogWrites) { Y_DEBUG_ABORT_UNLESS(logWrite); + logWrite->SpanStack.PopOk(); logOperationSizeBytes += logWrite->Data.size(); TStringStream errorReason; NKikimrProto::EReplyStatus status = ValidateRequest(logWrite, errorReason); if (status == NKikimrProto::OK) { + logWrite->SpanStack.Push(TWilson::PDisk, "PDisk.InBlockDevice", NWilson::EFlags::AUTO_END); LogWrite(*logWrite, logChunksToCommit); logWrite->ScheduleTime = HPNow(); - if (logWrite->Span) { - traceId = logWrite->Span.GetTraceId(); + if (auto logWriteTraceId = logWrite->SpanStack.GetTraceId()) { + traceId = std::move(logWriteTraceId); } } else { PrepareLogError(logWrite, errorReason, status); @@ -891,7 +895,7 @@ void TPDisk::LogWrite(TLogWrite &evLog, TVector &logChunksToCommit) { } // Write to log - auto evLogTraceId = evLog.Span.GetTraceId(); + auto evLogTraceId = evLog.SpanStack.GetTraceId(); CommonLogger->LogHeader(evLog.Owner, evLog.Signature, evLog.Lsn, payloadSize, evLog.ReqId, &evLogTraceId); OnNonceChange(NonceLog, evLog.ReqId, &evLogTraceId); if (evLog.Data.size()) { @@ -1264,7 +1268,7 @@ void TPDisk::OnLogCommitDone(TLogCommitDone &req) { WriteSysLogRestorePoint(completion.Release(), req.ReqId, {}); // FIXME: wilson } } - TryTrimChunk(false, 0, req.Span); + TryTrimChunk(false, 0, req.SpanStack.PeekTop() ? *req.SpanStack.PeekTop() : static_cast(NWilson::TSpan{})); } void TPDisk::MarkChunksAsReleased(TReleaseChunks& req) { @@ -1277,7 +1281,7 @@ void TPDisk::MarkChunksAsReleased(TReleaseChunks& req) { } if (req.IsChunksFromLogSplice) { - auto *releaseReq = ReqCreator.CreateFromArgs(std::move(req.ChunksToRelease), req.Span.CreateChild(TWilson::PDisk, "PDisk.ReleaseChunks")); + auto *releaseReq = ReqCreator.CreateFromArgs(std::move(req.ChunksToRelease), req.SpanStack.CreateChild(TWilson::PDisk, "PDisk.ReleaseChunks")); auto flushAction = MakeHolder(this, THolder(releaseReq)); @@ -1304,7 +1308,7 @@ void TPDisk::MarkChunksAsReleased(TReleaseChunks& req) { } IsLogChunksReleaseInflight = false; - TryTrimChunk(false, 0, req.Span); + TryTrimChunk(false, 0, req.SpanStack.PeekTop() ? *req.SpanStack.PeekTop() : static_cast(NWilson::TSpan{})); } } diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_req_creator.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_req_creator.h index 96fb97d2a1fd..c8ab252f8f7d 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_req_creator.h +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_req_creator.h @@ -192,7 +192,7 @@ class TReqCreator { auto& sender = ev->Sender; LOG_DEBUG_S(*ActorSystem, NKikimrServices::BS_PDISK, "PDiskId# " << PDiskId << " ev# " << ToString(ev) << " Sender# " << sender.LocalId() << " ReqId# " << AtomicGet(LastReqId)); - auto req = MakeHolder(ev, AtomicIncrement(LastReqId)); + auto req = MakeHolder(ev, PDiskId, AtomicIncrement(LastReqId)); NewRequest(req.Get(), burstMs); return req.Release(); } @@ -218,16 +218,18 @@ class TReqCreator { //////////////////////////////////////////////////////////////////////////////////////////////////////////////////// // TODO: Make all functions in style [[nodiscard]] TChunkTrim* CreateChunkTrim(ui32 chunkIdx, ui32 offset, ui64 size, const NWilson::TSpan& parent) { - NWilson::TSpan span = parent.CreateChild(TWilson::PDisk, "PDisk.TChunkTrim"); + NWilson::TSpan span = parent.CreateChild(TWilson::PDisk, "PDisk.ChunkTrim"); span.Attribute("chunk_idx", chunkIdx) .Attribute("offset", offset) - .Attribute("size", static_cast(size)); + .Attribute("size", static_cast(size)) + .Attribute("pdisk_id", PDiskId); Mon->Trim.CountRequest(size); return CreateFromArgs(chunkIdx, offset, size, std::move(span)); } [[nodiscard]] TLogWrite* CreateLogWrite(NPDisk::TEvLog &ev, const TActorId &sender, double& burstMs, NWilson::TTraceId traceId) { NWilson::TSpan span(TWilson::PDisk, std::move(traceId), "PDisk.LogWrite", NWilson::EFlags::AUTO_END, ActorSystem); + span.Attribute("pdisk_id", PDiskId); TReqId reqId(TReqId::LogWrite, AtomicIncrement(LastReqId)); LOG_DEBUG(*ActorSystem, NKikimrServices::BS_PDISK, "PDiskId# %" PRIu32 " %s Sender# %" PRIu64 " ReqId# %" PRIu64, @@ -244,6 +246,7 @@ class TReqCreator { [[nodiscard]] TChunkRead* CreateChunkRead(const NPDisk::TEvChunkRead &ev, const TActorId &sender, double& burstMs, NWilson::TTraceId traceId) { NWilson::TSpan span(TWilson::PDisk, std::move(traceId), "PDisk.ChunkRead", NWilson::EFlags::AUTO_END, ActorSystem); + span.Attribute("pdisk_id", PDiskId); TReqId reqId(TReqId::ChunkRead, AtomicIncrement(LastReqId)); LOG_DEBUG(*ActorSystem, NKikimrServices::BS_PDISK, "PDiskId# %" PRIu32 " %s Sender# %" PRIu64 " ReqId# %" PRIu64, @@ -259,6 +262,7 @@ class TReqCreator { [[nodiscard]] TChunkWrite* CreateChunkWrite(const NPDisk::TEvChunkWrite &ev, const TActorId &sender, double& burstMs, NWilson::TTraceId traceId) { NWilson::TSpan span(TWilson::PDisk, std::move(traceId), "PDisk.ChunkWrite", NWilson::EFlags::AUTO_END, ActorSystem); + span.Attribute("pdisk_id", PDiskId); TReqId reqId(TReqId::ChunkWrite, AtomicIncrement(LastReqId)); LOG_DEBUG(*ActorSystem, NKikimrServices::BS_PDISK, "PDiskId# %" PRIu32 " %s Sender# %" PRIu64 " ReqId# %" PRIu64, diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.cpp index b8ab31040a5e..f1b331932f4e 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.cpp @@ -9,7 +9,9 @@ namespace NPDisk { //////////////////////////////////////////////////////////////////////////////////////////////////////////////////////// void TRequestBase::AbortDelete(TRequestBase* request, TActorSystem* actorSystem) { - request->Span.EndError("Abort"); + while (auto span = request->SpanStack.Pop()) { + span.EndError("Abort"); + } switch(request->GetType()) { case ERequestType::RequestChunkRead: { diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.h index c8d3b18ca798..c7ebd692a905 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.h +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.h @@ -13,6 +13,7 @@ #include #include #include +#include #include #include @@ -55,7 +56,7 @@ class TRequestBase : public TThrRefBase { NHPTimer::STime ScheduleTime = 0; // Tracing - mutable NWilson::TSpan Span; + mutable NWilson::TSpanStack SpanStack; mutable NLWTrace::TOrbit Orbit; public: TRequestBase(const TActorId &sender, TReqId reqId, TOwner owner, TOwnerRound ownerRound, ui8 priorityClass, @@ -67,9 +68,11 @@ class TRequestBase : public TThrRefBase { , PriorityClass(priorityClass) , OwnerGroupType(EOwnerGroupType::Dynamic) , CreationTime(HPNow()) - , Span(std::move(span)) + , SpanStack(std::move(span)) { - Span.EnableAutoEnd(); + if (auto span = SpanStack.PeekTop()) { + span->EnableAutoEnd(); + } } void SetOwnerGroupType(bool isStaticGroupOwner) { @@ -180,13 +183,17 @@ class TLogRead : public TRequestBase { TLogPosition Position; ui64 SizeLimit; - TLogRead(const NPDisk::TEvReadLog::TPtr &ev, TAtomicBase reqIdx) + TLogRead(const NPDisk::TEvReadLog::TPtr &ev, ui32 pdiskId, TAtomicBase reqIdx) : TRequestBase(ev->Sender, TReqId(TReqId::LogRead, reqIdx), ev->Get()->Owner, ev->Get()->OwnerRound, NPriInternal::LogRead, NWilson::TSpan(TWilson::PDisk, std::move(ev->TraceId), "PDisk.LogRead")) , Position(ev->Get()->Position) , SizeLimit(ev->Get()->SizeLimit) { - Span.Attribute("size_limit", static_cast(ev->Get()->SizeLimit)); + if (auto span = SpanStack.PeekTop()) { + (*span) + .Attribute("size_limit", static_cast(ev->Get()->SizeLimit)) + .Attribute("pdisk_id", pdiskId); + } } ERequestType GetType() const override { @@ -205,7 +212,7 @@ class TLogReadContinue : public TRequestBase { TCompletionAction *CompletionAction; TReqId ReqId; - TLogReadContinue(const NPDisk::TEvReadLogContinue::TPtr &ev, TAtomicBase /*reqIdx*/) + TLogReadContinue(const NPDisk::TEvReadLogContinue::TPtr &ev, ui32 pdiskId, TAtomicBase /*reqIdx*/) : TRequestBase(ev->Sender, ev->Get()->ReqId, 0, 0, NPriInternal::LogRead, NWilson::TSpan(TWilson::PDisk, std::move(ev->TraceId), "PDisk.LogReadContinue")) , Data(ev->Get()->Data) @@ -214,8 +221,12 @@ class TLogReadContinue : public TRequestBase { , CompletionAction(ev->Get()->CompletionAction) , ReqId(ev->Get()->ReqId) { - Span.Attribute("size", ev->Get()->Size) - .Attribute("offset", static_cast(ev->Get()->Offset)); + if (auto span = SpanStack.PeekTop(); span) { + (*span) + .Attribute("size", ev->Get()->Size) + .Attribute("offset", static_cast(ev->Get()->Offset)) + .Attribute("pdisk_id", pdiskId); + } } ERequestType GetType() const override { @@ -837,11 +848,15 @@ class TYardControl : public TRequestBase { // class TAskForCutLog : public TRequestBase { public: - TAskForCutLog(const NPDisk::TEvAskForCutLog::TPtr &ev, TAtomicBase reqIdx) + TAskForCutLog(const NPDisk::TEvAskForCutLog::TPtr &ev, ui32 pdiskId, TAtomicBase reqIdx) : TRequestBase(ev->Sender, TReqId(TReqId::AskForCutLog, reqIdx), ev->Get()->Owner, ev->Get()->OwnerRound, NPriInternal::Other, NWilson::TSpan(TWilson::PDisk, std::move(ev->TraceId), "PDisk.AskForCutLog") ) - {} + { + if (auto span = SpanStack.PeekTop()) { + span->Attribute("pdisk_id", pdiskId); + } + } ERequestType GetType() const override { return ERequestType::RequestAskForCutLog; diff --git a/ydb/core/blobstorage/vdisk/huge/blobstorage_hullhuge.cpp b/ydb/core/blobstorage/vdisk/huge/blobstorage_hullhuge.cpp index ed7c977cc4f0..c27f6fb9b59e 100644 --- a/ydb/core/blobstorage/vdisk/huge/blobstorage_hullhuge.cpp +++ b/ydb/core/blobstorage/vdisk/huge/blobstorage_hullhuge.cpp @@ -11,6 +11,7 @@ #include #include #include +#include #include #include @@ -269,6 +270,7 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); ui64 Lsn; std::shared_ptr Pers; ui32 ChunkId = 0; + NWilson::TSpan Span; friend class TActorBootstrapped; @@ -328,6 +330,7 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); ctx.Send(NotifyID, new TEvHullHugeChunkAllocated(ChunkId)); Die(ctx); + Span.EndOk(); } STRICT_STFUNC(StateFunc, @@ -336,7 +339,11 @@ 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("Poison"); + Die(ctx); + } + PDISK_TERMINATE_STATE_FUNC_DEF; public: @@ -345,10 +352,11 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); } THullHugeBlobChunkAllocator(std::shared_ptr hugeKeeperCtx, const TActorId ¬ifyID, - std::shared_ptr pers) + std::shared_ptr pers, NWilson::TTraceId traceId) : HugeKeeperCtx(std::move(hugeKeeperCtx)) , NotifyID(notifyID) , Pers(std::move(pers)) + , Span(TWilson::VDiskTopLevel, std::move(traceId), "VDisk.HullHugeBlobChunkAllocator") {} }; @@ -550,7 +558,7 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); struct THullHugeKeeperState { ui64 WaitQueueSize = 0; ui64 WaitQueueByteSize = 0; - std::deque> WaitQueue; + std::deque>> WaitQueue; bool Committing = false; ui64 FreeUpToLsn = 0; // last value we got from PDisk @@ -644,10 +652,10 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); void PutToWaitQueue(std::unique_ptr item) { State.WaitQueueSize++; State.WaitQueueByteSize += item->Get()->ByteSize(); - State.WaitQueue.push_back(std::move(item)); + State.WaitQueue.emplace_back(std::move(item), NWilson::TSpan(TWilson::VDiskTopLevel, std::move(item->TraceId), "VDisk.HullHugeKeeper.InWaitQueue")); } - bool ProcessWrite(TEvHullWriteHugeBlob::THandle& ev, const TActorContext& ctx, bool fromWaitQueue) { + bool ProcessWrite(TEvHullWriteHugeBlob::THandle& ev, const TActorContext& ctx, bool fromWaitQueue, NWilson::TTraceId traceId) { auto& msg = *ev.Get(); NHuge::THugeSlot hugeSlot; ui32 slotSize; @@ -661,12 +669,12 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); Y_ABORT_UNLESS(inserted); const ui64 wId = State.LogLsnFifo.Push(HugeKeeperCtx->LsnMngr->GetLsn()); auto aid = ctx.Register(new THullHugeBlobWriter(HugeKeeperCtx, ctx.SelfID, hugeSlot, - std::unique_ptr(ev.Release().Release()), wId, std::move(ev.TraceId))); + std::unique_ptr(ev.Release().Release()), wId, std::move(traceId))); ActiveActors.Insert(aid, __FILE__, __LINE__, ctx, NKikimrServices::BLOBSTORAGE); return true; } else if (AllocatingChunkPerSlotSize.insert(slotSize).second) { LWTRACK(HugeBlobChunkAllocatorStart, ev.Get()->Orbit); - auto aid = ctx.RegisterWithSameMailbox(new THullHugeBlobChunkAllocator(HugeKeeperCtx, ctx.SelfID, State.Pers)); + auto aid = ctx.RegisterWithSameMailbox(new THullHugeBlobChunkAllocator(HugeKeeperCtx, ctx.SelfID, State.Pers, std::move(traceId))); ActiveActors.Insert(aid, __FILE__, __LINE__, ctx, NKikimrServices::BLOBSTORAGE); } return false; @@ -674,7 +682,8 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); void ProcessQueue(const TActorContext &ctx) { auto it = State.WaitQueue.begin(); - while (it != State.WaitQueue.end() && ProcessWrite(**it, ctx, true)) { + while (it != State.WaitQueue.end() && ProcessWrite(*it->Item, ctx, true, it->Span.GetTraceId())) { + it->Span.EndOk(); ++it; } State.WaitQueue.erase(State.WaitQueue.begin(), it); @@ -768,7 +777,7 @@ LWTRACE_USING(BLOBSTORAGE_PROVIDER); "THullHugeKeeper: TEvHullWriteHugeBlob: %s", std::data(ev->Get()->ToString()))); LWTRACK(HugeKeeperWriteHugeBlobReceived, ev->Get()->Orbit); std::unique_ptr item(ev.Release()); - if (!ProcessWrite(*item, ctx, false)) { + if (!ProcessWrite(*item, ctx, false, item->TraceId.Clone())) { PutToWaitQueue(std::move(item)); } } diff --git a/ydb/library/actors/wilson/wilson_span.h b/ydb/library/actors/wilson/wilson_span.h index b44cb6406a2e..c1efe517b961 100644 --- a/ydb/library/actors/wilson/wilson_span.h +++ b/ydb/library/actors/wilson/wilson_span.h @@ -179,7 +179,7 @@ namespace NWilson { return *this; } - template>> + template>> TSpan& Event(T&& name, T1&& attributes) { if (Y_UNLIKELY(*this)) { auto *event = Data->Span.add_events(); diff --git a/ydb/library/actors/wilson/wilson_span_stack.h b/ydb/library/actors/wilson/wilson_span_stack.h new file mode 100644 index 000000000000..7772ee258bbb --- /dev/null +++ b/ydb/library/actors/wilson/wilson_span_stack.h @@ -0,0 +1,84 @@ +#pragma once + +#include "wilson_span.h" + +#include + +namespace NWilson { + + class TSpanStack { + public: + TSpanStack(TSpan&& root) { + if (root) { + Top = std::make_unique(std::move(root)); + } + } + + template + TSpan* Push(ui8 verbosity, T&& name, TFlags flags = EFlags::NONE) { + auto span = CreateChild(verbosity, std::forward(name), flags); + if (span) { + Top = std::make_unique(std::move(span), std::move(Top)); + return &Top->Span; + } + return nullptr; + } + + template + TSpan CreateChild(ui8 verbosity, T&& name, TFlags flags = EFlags::NONE) const { + if (auto span = PeekTop()) { + return span->CreateChild(verbosity, std::forward(name), flags); + } + return {}; + } + + TTraceId GetTraceId() const { + if (auto span = PeekTop()) { + return span->GetTraceId(); + } + return {}; + } + + TSpan Pop() { + if (!Top) { + return {}; + } + auto prevTop = std::exchange(Top, std::move(Top->Next)); + return std::move(prevTop->Span); + } + + void PopOk() { + Pop().EndOk(); + } + + template + void PopError(T&& error) { + Pop().EndError(std::forward(error)); + } + + TSpan* PeekTop() const { + if (!Top) { + return nullptr; + } + return &Top->Span; + } + + private: + struct TStackNode { + TStackNode(TSpan&& span, std::unique_ptr next) + : Span(std::move(span)) + , Next(std::move(next)) + {} + + TStackNode(TSpan&& span) + : TStackNode(std::move(span), {}) + {} + + TSpan Span; + std::unique_ptr Next; + }; + + std::unique_ptr Top; + }; + +} //namespace NWilson diff --git a/ydb/library/actors/wilson/wilson_with_span.h b/ydb/library/actors/wilson/wilson_with_span.h new file mode 100644 index 000000000000..6d05662a22d4 --- /dev/null +++ b/ydb/library/actors/wilson/wilson_with_span.h @@ -0,0 +1,18 @@ +#pragma once + +#include "wilson_span.h" + +namespace NWilson { + +template +struct TWithSpan { + TWithSpan(T&& item, NWilson::TSpan&& span) + : Item(std::forward(item)) + , Span(std::move(span)) + {} + + T Item; + NWilson::TSpan Span; +}; + +} From 14db63a4b07d850f5ea7690fc13b28196e358642 Mon Sep 17 00:00:00 2001 From: Oleg Shatov Date: Tue, 9 Jan 2024 06:36:30 +0000 Subject: [PATCH 2/7] Introduced span for TChunkReadPartCompletion --- .../blobstorage_pdisk_completion_impl.cpp | 10 +++------- .../pdisk/blobstorage_pdisk_completion_impl.h | 4 ++-- .../pdisk/blobstorage_pdisk_impl.cpp | 9 +++++---- .../pdisk/blobstorage_pdisk_impl.h | 2 +- .../pdisk/blobstorage_pdisk_requestimpl.h | 2 +- ydb/library/actors/wilson/wilson_span_stack.h | 2 +- ydb/library/actors/wilson/wilson_with_span.h | 20 +++++++++---------- 7 files changed, 23 insertions(+), 26 deletions(-) diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp index 2c0796fe6701..61b8bc1ec255 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp @@ -116,7 +116,7 @@ void TCompletionLogWrite::Release(TActorSystem *actorSystem) { TCompletionChunkReadPart::TCompletionChunkReadPart(TPDisk *pDisk, TIntrusivePtr &read, ui64 rawReadSize, ui64 payloadReadSize, ui64 commonBufferOffset, TCompletionChunkRead *cumulativeCompletion, bool isTheLastPart, - const TControlWrapper& useT1ha0Hasher) + const TControlWrapper& useT1ha0Hasher, NWilson::TSpan&& span) : TCompletionAction() , PDisk(pDisk) , Read(read) @@ -127,6 +127,7 @@ TCompletionChunkReadPart::TCompletionChunkReadPart(TPDisk *pDisk, TIntrusivePtr< , Buffer(PDisk->BufferPool->Pop()) , IsTheLastPart(isTheLastPart) , UseT1ha0Hasher(useT1ha0Hasher) + , Span(std::move(span)) { if (!IsTheLastPart) { CumulativeCompletion->AddPart(); @@ -145,6 +146,7 @@ TBuffer *TCompletionChunkReadPart::GetBuffer() { } void TCompletionChunkReadPart::Exec(TActorSystem *actorSystem) { + Span.Event("exec", {}); Y_ABORT_UNLESS(actorSystem); Y_ABORT_UNLESS(CumulativeCompletion); if (TCompletionAction::Result != EIoResult::Ok) { @@ -344,12 +346,6 @@ void TCompletionChunkRead::ReplyError(TActorSystem *actorSystem, TString reason) // Returns true if there is some pending requests to wait bool TCompletionChunkRead::PartReadComplete(TActorSystem *actorSystem) { TAtomicBase partsPending = AtomicDecrement(PartsPending); - { - TGuard lk(SpanStackLock); - if (auto span = Read->SpanStack.PeekTop()) { - span->Event("PartReadComplete"); - } - } if (partsPending == 0) { if (AtomicGet(Deletes) == 0) { Exec(actorSystem); diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h index c303e2458fed..a98cbb243e2d 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h @@ -160,7 +160,6 @@ class TCompletionChunkRead : public TCompletionAction { TAtomic Deletes; std::function OnDestroy; ui64 ChunkNonce; - TMutex SpanStackLock; const ui64 DoubleFreeCanary; public: @@ -216,10 +215,11 @@ class TCompletionChunkReadPart : public TCompletionAction { TBuffer::TPtr Buffer; bool IsTheLastPart; TControlWrapper UseT1ha0Hasher; + NWilson::TSpan Span; public: TCompletionChunkReadPart(TPDisk *pDisk, TIntrusivePtr &read, ui64 rawReadSize, ui64 payloadReadSize, ui64 commonBufferOffset, TCompletionChunkRead *cumulativeCompletion, bool isTheLastPart, - const TControlWrapper& useT1ha0Hasher); + const TControlWrapper& useT1ha0Hasher, NWilson::TSpan&& span); bool CanHandleResult() const override { diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp index 7959c1b53a18..ac21fbbab5ac 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp @@ -987,7 +987,7 @@ void TPDisk::SendChunkReadError(const TIntrusivePtr& read, TStringSt } TPDisk::EChunkReadPieceResult TPDisk::ChunkReadPiece(TIntrusivePtr &read, ui64 pieceCurrentSector, - ui64 pieceSizeLimit, ui64 *reallyReadDiskBytes) { + ui64 pieceSizeLimit, ui64 *reallyReadDiskBytes, NWilson::TTraceId traceId) { if (read->IsReplied) { return ReadPieceResultOk; } @@ -1051,12 +1051,13 @@ TPDisk::EChunkReadPieceResult TPDisk::ChunkReadPiece(TIntrusivePtr & ui64 readOffset = Format.Offset(read->ChunkIdx, read->FirstSector, currentSectorOffset); // TODO: Get this from the drive + NWilson::TSpan span(TWilson::PDisk, std::move(traceId), "PDisk.ChunkReadPiece.Completion", NWilson::EFlags::AUTO_END, ActorSystem); + traceId = span.GetTraceId(); THolder completion(new TCompletionChunkReadPart(this, read, bytesToRead, - payloadBytesToRead, payloadOffset, read->FinalCompletion, isTheLastPart, Cfg->UseT1ha0HashInFooter)); + payloadBytesToRead, payloadOffset, read->FinalCompletion, isTheLastPart, Cfg->UseT1ha0HashInFooter, std::move(span))); completion->CostNs = DriveModel.TimeForSizeNs(bytesToRead, read->ChunkIdx, TDriveModel::OP_TYPE_READ); Y_ABORT_UNLESS(bytesToRead <= completion->GetBuffer()->Size()); ui8 *data = completion->GetBuffer()->Data(); - auto traceId = read->SpanStack.GetTraceId(); BlockDevice->PreadAsync(data, bytesToRead, readOffset, completion.Release(), read->ReqId, &traceId); // TODO: align the data on SectorSize, not PAGE_SIZE @@ -2301,7 +2302,7 @@ void TPDisk::ProcessChunkReadQueue() { ui64 currentLimit = Min(bufferSize, piece->PieceSizeLimit - size); ui64 reallyReadDiskBytes; EChunkReadPieceResult result = ChunkReadPiece(read, piece->PieceCurrentSector + size / Format.SectorSize, - currentLimit, &reallyReadDiskBytes); + currentLimit, &reallyReadDiskBytes, piece->SpanStack.GetTraceId()); isComplete = (result != ReadPieceResultInProgress); // Read pieces is sliced previously and it is expected that ChunkReadPiece will read exactly // currentLimit bytes diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.h index f4b83ffb6a59..ffc694049664 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.h +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.h @@ -288,7 +288,7 @@ class TPDisk : public IPDisk { void SendChunkReadError(const TIntrusivePtr& read, TStringStream& errorReason, NKikimrProto::EReplyStatus status); EChunkReadPieceResult ChunkReadPiece(TIntrusivePtr &read, ui64 pieceCurrentSector, ui64 pieceSizeLimit, - ui64 *reallyReadBytes); + ui64 *reallyReadBytes, NWilson::TTraceId traceId); void SplitChunkJobSize(ui32 totalSize, ui32 *outSmallJobSize, ui32 *outLargeJObSize, ui32 *outSmallJobCount); //////////////////////////////////////////////////////////////////////////////////////////////////////////////////// // Chunk locking diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.h index c7ebd692a905..ee89bc085331 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.h +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_requestimpl.h @@ -221,7 +221,7 @@ class TLogReadContinue : public TRequestBase { , CompletionAction(ev->Get()->CompletionAction) , ReqId(ev->Get()->ReqId) { - if (auto span = SpanStack.PeekTop(); span) { + if (auto span = SpanStack.PeekTop()) { (*span) .Attribute("size", ev->Get()->Size) .Attribute("offset", static_cast(ev->Get()->Offset)) diff --git a/ydb/library/actors/wilson/wilson_span_stack.h b/ydb/library/actors/wilson/wilson_span_stack.h index 7772ee258bbb..5b151b82ca88 100644 --- a/ydb/library/actors/wilson/wilson_span_stack.h +++ b/ydb/library/actors/wilson/wilson_span_stack.h @@ -81,4 +81,4 @@ namespace NWilson { std::unique_ptr Top; }; -} //namespace NWilson +} // NWilson diff --git a/ydb/library/actors/wilson/wilson_with_span.h b/ydb/library/actors/wilson/wilson_with_span.h index 6d05662a22d4..93ee38081733 100644 --- a/ydb/library/actors/wilson/wilson_with_span.h +++ b/ydb/library/actors/wilson/wilson_with_span.h @@ -4,15 +4,15 @@ namespace NWilson { -template -struct TWithSpan { - TWithSpan(T&& item, NWilson::TSpan&& span) - : Item(std::forward(item)) - , Span(std::move(span)) - {} + template + struct TWithSpan { + TWithSpan(T&& item, NWilson::TSpan&& span) + : Item(std::forward(item)) + , Span(std::move(span)) + {} - T Item; - NWilson::TSpan Span; -}; + T Item; + NWilson::TSpan Span; + }; -} +} // NWilson From 1806fbee322f3eb19ee3db352dedcfa924e6d2a8 Mon Sep 17 00:00:00 2001 From: Oleg Shatov Date: Wed, 10 Jan 2024 06:13:57 +0000 Subject: [PATCH 3/7] Added span to CompletionChunkWrite --- .../blobstorage/pdisk/blobstorage_pdisk_completion_impl.h | 7 ++++++- ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp | 3 ++- 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h index a98cbb243e2d..a5ae6907dd6d 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h @@ -75,11 +75,13 @@ class TCompletionChunkWrite : public TCompletionAction { ui8 PriorityClass; std::function OnDestroy; TReqId ReqId; + NWilson::TSpan Span; public: TCompletionChunkWrite(const TActorId &recipient, TEvChunkWriteResult *event, TPDiskMon *mon, ui32 pdiskId, NHPTimer::STime startTime, size_t sizeBytes, - ui8 priorityClass, std::function onDestroy, TReqId reqId) + ui8 priorityClass, std::function onDestroy, TReqId reqId, + NWilson::TSpan&& span) : Recipient(recipient) , Event(event) , Mon(mon) @@ -89,6 +91,7 @@ class TCompletionChunkWrite : public TCompletionAction { , PriorityClass(priorityClass) , OnDestroy(std::move(onDestroy)) , ReqId(reqId) + , Span(std::move(span)) { } @@ -98,6 +101,7 @@ class TCompletionChunkWrite : public TCompletionAction { void Exec(TActorSystem *actorSystem) override { double responseTimeMs = HPMilliSecondsFloat(HPNow() - StartTime); + Span.EndOk(); LOG_DEBUG_S(*actorSystem, NKikimrServices::BS_PDISK, "PDiskId# " << PDiskId << " ReqId# " << ReqId << "TCompletionChunkWrite " << Event->ToString().data() @@ -115,6 +119,7 @@ class TCompletionChunkWrite : public TCompletionAction { } void Release(TActorSystem *actorSystem) override { + Span.EndError(ErrorReason); Event->Status = NKikimrProto::CORRUPTED; Event->ErrorReason = ErrorReason; actorSystem->Send(Recipient, Event.Release()); diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp index ac21fbbab5ac..620bc43e3745 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp @@ -2972,7 +2972,8 @@ bool TPDisk::PreprocessRequest(TRequestBase *request) { --inFlight->ChunkWrites; }; ev.Completion = MakeHolder(ev.Sender, result.release(), &Mon, PDiskId, - ev.CreationTime, ev.TotalSize, ev.PriorityClass, std::move(onDestroy), ev.ReqId); + ev.CreationTime, ev.TotalSize, ev.PriorityClass, std::move(onDestroy), ev.ReqId, + ev.SpanStack.CreateChild(TWilson::PDisk, "PDisk.ChunkWrite.Completion")); return true; } From 30ab000100025b8b119c8d29daa330a331ad1dad Mon Sep 17 00:00:00 2001 From: Oleg Shatov Date: Thu, 11 Jan 2024 03:01:00 +0000 Subject: [PATCH 4/7] Comments fixed --- .../pdisk/blobstorage_pdisk_impl_log.cpp | 4 +- ydb/library/actors/wilson/wilson_span.cpp | 2 + ydb/library/actors/wilson/wilson_span.h | 2 + ydb/library/actors/wilson/wilson_span_stack.h | 55 ++++++++----------- 4 files changed, 28 insertions(+), 35 deletions(-) diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl_log.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl_log.cpp index ad5cc3d91e6f..dfa78979f08b 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl_log.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl_log.cpp @@ -1268,7 +1268,7 @@ void TPDisk::OnLogCommitDone(TLogCommitDone &req) { WriteSysLogRestorePoint(completion.Release(), req.ReqId, {}); // FIXME: wilson } } - TryTrimChunk(false, 0, req.SpanStack.PeekTop() ? *req.SpanStack.PeekTop() : static_cast(NWilson::TSpan{})); + TryTrimChunk(false, 0, req.SpanStack.PeekTopConst()); } void TPDisk::MarkChunksAsReleased(TReleaseChunks& req) { @@ -1308,7 +1308,7 @@ void TPDisk::MarkChunksAsReleased(TReleaseChunks& req) { } IsLogChunksReleaseInflight = false; - TryTrimChunk(false, 0, req.SpanStack.PeekTop() ? *req.SpanStack.PeekTop() : static_cast(NWilson::TSpan{})); + TryTrimChunk(false, 0, req.SpanStack.PeekTopConst()); } } diff --git a/ydb/library/actors/wilson/wilson_span.cpp b/ydb/library/actors/wilson/wilson_span.cpp index f0626448078e..ac66ac2ef002 100644 --- a/ydb/library/actors/wilson/wilson_span.cpp +++ b/ydb/library/actors/wilson/wilson_span.cpp @@ -62,4 +62,6 @@ namespace NWilson { Data->Sent = true; } + const TSpan TSpan::Empty; + } // NWilson diff --git a/ydb/library/actors/wilson/wilson_span.h b/ydb/library/actors/wilson/wilson_span.h index c1efe517b961..826e96257835 100644 --- a/ydb/library/actors/wilson/wilson_span.h +++ b/ydb/library/actors/wilson/wilson_span.h @@ -261,6 +261,8 @@ namespace NWilson { return TSpan(verbosity, GetTraceId(), std::move(name), flags, GetActorSystem()); } + static const TSpan Empty; + private: void Send(); diff --git a/ydb/library/actors/wilson/wilson_span_stack.h b/ydb/library/actors/wilson/wilson_span_stack.h index 5b151b82ca88..1d6ed3d0f74e 100644 --- a/ydb/library/actors/wilson/wilson_span_stack.h +++ b/ydb/library/actors/wilson/wilson_span_stack.h @@ -2,7 +2,8 @@ #include "wilson_span.h" -#include +#include +#include namespace NWilson { @@ -10,7 +11,7 @@ namespace NWilson { public: TSpanStack(TSpan&& root) { if (root) { - Top = std::make_unique(std::move(root)); + Stack.push(std::move(root)); } } @@ -18,33 +19,28 @@ namespace NWilson { TSpan* Push(ui8 verbosity, T&& name, TFlags flags = EFlags::NONE) { auto span = CreateChild(verbosity, std::forward(name), flags); if (span) { - Top = std::make_unique(std::move(span), std::move(Top)); - return &Top->Span; + Stack.push(std::move(span)); + return &Stack.top(); } return nullptr; } template TSpan CreateChild(ui8 verbosity, T&& name, TFlags flags = EFlags::NONE) const { - if (auto span = PeekTop()) { - return span->CreateChild(verbosity, std::forward(name), flags); - } - return {}; + return PeekTopConst().CreateChild(verbosity, std::forward(name), flags); } TTraceId GetTraceId() const { - if (auto span = PeekTop()) { - return span->GetTraceId(); - } - return {}; + return PeekTopConst().GetTraceId(); } TSpan Pop() { - if (!Top) { + if (Stack.empty()) { return {}; } - auto prevTop = std::exchange(Top, std::move(Top->Next)); - return std::move(prevTop->Span); + auto top = std::move(Stack.top()); + Stack.pop(); + return top; } void PopOk() { @@ -56,29 +52,22 @@ namespace NWilson { Pop().EndError(std::forward(error)); } - TSpan* PeekTop() const { - if (!Top) { + TSpan* PeekTop() { + if (Stack.empty()) { return nullptr; } - return &Top->Span; + return &Stack.top(); } - private: - struct TStackNode { - TStackNode(TSpan&& span, std::unique_ptr next) - : Span(std::move(span)) - , Next(std::move(next)) - {} - - TStackNode(TSpan&& span) - : TStackNode(std::move(span), {}) - {} - - TSpan Span; - std::unique_ptr Next; - }; + const TSpan& PeekTopConst() const { + if (Stack.empty()) { + return TSpan::Empty; + } + return Stack.top(); + } - std::unique_ptr Top; + private: + std::stack> Stack; }; } // NWilson From c9e8d194f89648e69b2ef892811a3f96a0c6fabb Mon Sep 17 00:00:00 2001 From: Oleg Shatov Date: Fri, 12 Jan 2024 01:42:38 +0000 Subject: [PATCH 5/7] Joined spans of the scheduler --- .../pdisk/blobstorage_pdisk_impl.cpp | 36 +++++++++++-------- 1 file changed, 21 insertions(+), 15 deletions(-) diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp index 620bc43e3745..0d8ab944cc9e 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp @@ -3168,7 +3168,7 @@ void TPDisk::PushRequestToForseti(TRequestBase *request) { && static_cast(job->Payload)->GetType() == ERequestType::RequestLogWrite) { TLogWrite &batch = *static_cast(job->Payload); - if (auto span = request->SpanStack.Push(TWilson::PDisk, "PDisk.InForseti.InBatch")) { + if (auto span = request->SpanStack.Push(TWilson::PDisk, "PDisk.InScheduler.InLogWriteBatch")) { span->Attribute("Batch.ReqId", static_cast(batch.ReqId.Id)); } batch.AddToBatch(static_cast(request)); @@ -3271,7 +3271,7 @@ void TPDisk::SplitChunkJobSize(ui32 totalSize, ui32 *outSmallJobSize, ui32 *outL void TPDisk::AddJobToForseti(NSchLab::TCbs *cbs, TRequestBase *request, NSchLab::EJobKind jobKind) { LWTRACK(PDiskAddToScheduler, request->Orbit, PDiskId, request->ReqId.Id, HPSecondsFloat(request->CreationTime), request->Owner, request->IsFast, request->PriorityClass); - request->SpanStack.Push(TWilson::PDisk, "PDisk.InForseti"); + request->SpanStack.Push(TWilson::PDisk, "PDisk.InScheduler"); TIntrusivePtr job = ForsetiScheduler.CreateJob(); job->Payload = request; job->Cost = request->Cost; @@ -3298,29 +3298,33 @@ void TPDisk::RouteRequest(TRequestBase *request) { case ERequestType::RequestLogReadResultProcess: [[fallthrough]]; case ERequestType::RequestLogSectorRestore: - request->SpanStack.PopOk(); - request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointLogReads"); + if (auto span = request->SpanStack.PeekTop()) { + span->Event("move_to_batcher", {}); + } JointLogReads.push_back(request); break; case ERequestType::RequestChunkReadPiece: { TChunkReadPiece *piece = static_cast(request); - request->SpanStack.PopOk(); - request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointChunkReads"); + if (auto span = request->SpanStack.PeekTop()) { + span->Event("move_to_batcher", {}); + } JointChunkReads.emplace_back(piece->SelfPointer.Get()); piece->SelfPointer.Reset(); // FIXME(cthulhu): Unreserve() for TChunkReadPiece is called while processing to avoid requeueing issues break; } case ERequestType::RequestChunkWritePiece: - request->SpanStack.PopOk(); - request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointChunkWrites"); + if (auto span = request->SpanStack.PeekTop()) { + span->Event("move_to_batcher", {}); + } JointChunkWrites.push_back(request); break; case ERequestType::RequestChunkTrim: { - request->SpanStack.PopOk(); - request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointChunkTrims"); + if (auto span = request->SpanStack.PeekTop()) { + span->Event("move_to_batcher", {}); + } TChunkTrim *trim = static_cast(request); JointChunkTrims.push_back(trim); break; @@ -3331,9 +3335,10 @@ void TPDisk::RouteRequest(TRequestBase *request) { while (log) { TLogWrite *batch = log->PopFromBatch(); - log->SpanStack.PopOk(); - if (auto span = log->SpanStack.Push(TWilson::PDisk, "PDisk.InJointLogWrites")) { - span->Attribute("HasCommitRecord", log->Signature.HasCommitRecord()); + if (auto span = log->SpanStack.PeekTop()) { + (*span) + .Event("move_to_batcher", {}) + .Attribute("HasCommitRecord", log->Signature.HasCommitRecord()); } JointLogWrites.push_back(log); if (log->Signature.HasCommitRecord()) { @@ -3345,8 +3350,9 @@ void TPDisk::RouteRequest(TRequestBase *request) { } case ERequestType::RequestChunkForget: { - request->SpanStack.PopOk(); - request->SpanStack.Push(TWilson::PDisk, "PDisk.InJointChunkForgets"); + if (auto span = request->SpanStack.PeekTop()) { + span->Event("move_to_batcher", {}); + } TChunkForget *forget = static_cast(request); JointChunkForgets.push_back(std::unique_ptr(forget)); break; From a0a199bb585691f6e2f944e611a0610188952e22 Mon Sep 17 00:00:00 2001 From: Oleg Shatov Date: Fri, 12 Jan 2024 09:46:03 +0000 Subject: [PATCH 6/7] Fixed some other issues --- .../pdisk/blobstorage_pdisk_completion_impl.cpp | 8 +++++++- .../pdisk/blobstorage_pdisk_completion_impl.h | 11 ++++++++--- ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp | 7 ++++--- 3 files changed, 19 insertions(+), 7 deletions(-) diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp index 61b8bc1ec255..90f22ebd94ae 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.cpp @@ -146,7 +146,7 @@ TBuffer *TCompletionChunkReadPart::GetBuffer() { } void TCompletionChunkReadPart::Exec(TActorSystem *actorSystem) { - Span.Event("exec", {}); + auto execSpan = Span.CreateChild(TWilson::PDisk, "PDisk.CompletionChunkReadPart.Exec"); Y_ABORT_UNLESS(actorSystem); Y_ABORT_UNLESS(CumulativeCompletion); if (TCompletionAction::Result != EIoResult::Ok) { @@ -281,6 +281,8 @@ void TCompletionChunkReadPart::Exec(TActorSystem *actorSystem) { AtomicSub(PDisk->InFlightChunkRead, RawReadSize); RawReadSize = 0; + execSpan.EndOk(); + Span.EndOk(); delete this; } @@ -291,6 +293,7 @@ void TCompletionChunkReadPart::Release(TActorSystem *actorSystem) { } AtomicSub(PDisk->InFlightChunkRead, RawReadSize); RawReadSize = 0; + Span.EndError("release"); delete this; } @@ -303,6 +306,7 @@ TCompletionChunkRead::~TCompletionChunkRead() { } void TCompletionChunkRead::Exec(TActorSystem *actorSystem) { + auto execSpan = Span.CreateChild(TWilson::PDisk, "PDisk.CompletionChunkRead.Exec"); THolder result = MakeHolder(NKikimrProto::OK, Read->ChunkIdx, Read->Offset, Read->Cookie, PDisk->GetStatusFlags(Read->Owner, Read->OwnerGroupType), ""); result->Data = std::move(CommonBuffer); @@ -323,6 +327,8 @@ void TCompletionChunkRead::Exec(TActorSystem *actorSystem) { actorSystem->Send(Read->Sender, result.Release()); Read->IsReplied = true; PDisk->Mon.GetReadCounter(Read->PriorityClass)->CountResponse(); + execSpan.EndOk(); + Span.EndOk(); delete this; } diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h index a5ae6907dd6d..415f5a2549e3 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_completion_impl.h @@ -100,8 +100,8 @@ class TCompletionChunkWrite : public TCompletionAction { } void Exec(TActorSystem *actorSystem) override { + auto execSpan = Span.CreateChild(TWilson::PDisk, "PDisk.CompletionChunkWrite.Exec"); double responseTimeMs = HPMilliSecondsFloat(HPNow() - StartTime); - Span.EndOk(); LOG_DEBUG_S(*actorSystem, NKikimrServices::BS_PDISK, "PDiskId# " << PDiskId << " ReqId# " << ReqId << "TCompletionChunkWrite " << Event->ToString().data() @@ -115,14 +115,16 @@ class TCompletionChunkWrite : public TCompletionAction { if (Mon) { Mon->GetWriteCounter(PriorityClass)->CountResponse(); } + execSpan.EndOk(); + Span.EndOk(); delete this; } void Release(TActorSystem *actorSystem) override { - Span.EndError(ErrorReason); Event->Status = NKikimrProto::CORRUPTED; Event->ErrorReason = ErrorReason; actorSystem->Send(Recipient, Event.Release()); + Span.EndError(ErrorReason); delete this; } }; @@ -165,11 +167,12 @@ class TCompletionChunkRead : public TCompletionAction { TAtomic Deletes; std::function OnDestroy; ui64 ChunkNonce; + NWilson::TSpan Span; const ui64 DoubleFreeCanary; public: TCompletionChunkRead(TPDisk *pDisk, TIntrusivePtr &read, std::function onDestroy, - ui64 chunkNonce) + ui64 chunkNonce, NWilson::TSpan&& span) : TCompletionAction() , PDisk(pDisk) , Read(read) @@ -179,6 +182,7 @@ class TCompletionChunkRead : public TCompletionAction { , Deletes(0) , OnDestroy(std::move(onDestroy)) , ChunkNonce(chunkNonce) + , Span(std::move(span)) , DoubleFreeCanary(ReferenceCanary) {} @@ -207,6 +211,7 @@ class TCompletionChunkRead : public TCompletionAction { void Release(TActorSystem *actorSystem) override { ReplyError(actorSystem, "TCompletionChunkRead is released"); + Span.EndError("release"); } }; diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp index 0d8ab944cc9e..6a6c4700fd3d 100644 --- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp +++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_impl.cpp @@ -1051,7 +1051,7 @@ TPDisk::EChunkReadPieceResult TPDisk::ChunkReadPiece(TIntrusivePtr & ui64 readOffset = Format.Offset(read->ChunkIdx, read->FirstSector, currentSectorOffset); // TODO: Get this from the drive - NWilson::TSpan span(TWilson::PDisk, std::move(traceId), "PDisk.ChunkReadPiece.Completion", NWilson::EFlags::AUTO_END, ActorSystem); + NWilson::TSpan span(TWilson::PDisk, std::move(traceId), "PDisk.CompletionChunkReadPart", NWilson::EFlags::NONE, ActorSystem); traceId = span.GetTraceId(); THolder completion(new TCompletionChunkReadPart(this, read, bytesToRead, payloadBytesToRead, payloadOffset, read->FinalCompletion, isTheLastPart, Cfg->UseT1ha0HashInFooter, std::move(span))); @@ -2888,7 +2888,8 @@ bool TPDisk::PreprocessRequest(TRequestBase *request) { --state.OperationsInProgress; --inFlight->ChunkReads; }; - read->FinalCompletion = new TCompletionChunkRead(this, read, std::move(onDestroy), state.Nonce); + auto completionSpan = request->SpanStack.CreateChild(TWilson::PDisk, "PDisk.CompletionChunkRead"); + read->FinalCompletion = new TCompletionChunkRead(this, read, std::move(onDestroy), state.Nonce, std::move(completionSpan)); static_cast(request)->SelfPointer = std::move(read); @@ -2973,7 +2974,7 @@ bool TPDisk::PreprocessRequest(TRequestBase *request) { }; ev.Completion = MakeHolder(ev.Sender, result.release(), &Mon, PDiskId, ev.CreationTime, ev.TotalSize, ev.PriorityClass, std::move(onDestroy), ev.ReqId, - ev.SpanStack.CreateChild(TWilson::PDisk, "PDisk.ChunkWrite.Completion")); + ev.SpanStack.CreateChild(TWilson::PDisk, "PDisk.CompletionChunkWrite")); return true; } From d98ec9edf583fd7a8d50050023b7c486f69cc0f5 Mon Sep 17 00:00:00 2001 From: Oleg Shatov Date: Fri, 12 Jan 2024 10:03:56 +0000 Subject: [PATCH 7/7] Minor improvement --- ydb/library/actors/wilson/wilson_span_stack.h | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/ydb/library/actors/wilson/wilson_span_stack.h b/ydb/library/actors/wilson/wilson_span_stack.h index 1d6ed3d0f74e..2d7710f91b12 100644 --- a/ydb/library/actors/wilson/wilson_span_stack.h +++ b/ydb/library/actors/wilson/wilson_span_stack.h @@ -17,8 +17,7 @@ namespace NWilson { template TSpan* Push(ui8 verbosity, T&& name, TFlags flags = EFlags::NONE) { - auto span = CreateChild(verbosity, std::forward(name), flags); - if (span) { + if (auto span = CreateChild(verbosity, std::forward(name), flags)) { Stack.push(std::move(span)); return &Stack.top(); }