Fix disk cost metrics calculations, add UT for dsproxy and vdisk, KIKIMR-17759

Fix disk cost metrics calculations, add UT for dsproxy and vdisk

11 files changed, 317 insertions, 9 deletions

diff --git a/ydb/core/blobstorage/dsproxy/dsproxy.h b/ydb/core/blobstorage/dsproxy/dsproxy.h
index 2a1f64a24c..19a11f366b 100644
--- a/ydb/core/blobstorage/dsproxy/dsproxy.h
+++ b/ydb/core/blobstorage/dsproxy/dsproxy.h
@@ -369,12 +369,17 @@ public:
     void SendToQueue(std::unique_ptr<T> event, ui64 cookie, bool timeStatsEnabled = false) {
         if constexpr (!std::is_same_v<T, TEvBlobStorage::TEvVStatus> && !std::is_same_v<T, TEvBlobStorage::TEvVAssimilate>) {
             event->MessageRelevanceTracker = MessageRelevanceTracker;
+            ui64 cost;
             if constexpr (std::is_same_v<T, TEvBlobStorage::TEvVMultiPut>) {
                 bool internalQueue;
-                SentSubrequestCost += CostModel->GetCost(*event, &internalQueue);
+                cost = CostModel->GetCost(*event, &internalQueue);
             } else {
-                SentSubrequestCost += CostModel->GetCost(*event);
+                cost = CostModel->GetCost(*event);
             }
+            *PoolCounters->DSProxyDiskCostCounter += cost;
+
+            LOG_TRACE_S(TActivationContext::AsActorContext(), NKikimrServices::BS_REQUEST_COST,
+                    "DSProxy Request Type# " << TypeName(*event) << " Cost# " << cost);
         }
 
         const TActorId queueId = GroupQueues->Send(*this, Info->GetTopology(), std::move(event), cookie, Span.GetTraceId(),
@@ -509,7 +514,6 @@ public:
         if (RequestHandleClass && PoolCounters) {
             PoolCounters->GetItem(*RequestHandleClass, RequestBytes).Register(
                 RequestBytes, GeneratedSubrequests, GeneratedSubrequestBytes, Timer.Passed());
-            *PoolCounters->DSProxyDiskCostCounter += SentSubrequestCost;
         }
 
         if (timeStats) {
@@ -581,7 +585,6 @@ protected:
     ui32 RequestBytes = 0;
     ui32 GeneratedSubrequests = 0;
     ui32 GeneratedSubrequestBytes = 0;
-    ui64 SentSubrequestCost = 0;
     bool Dead = false;
     const ui32 RestartCounter = 0;
     std::shared_ptr<const TCostModel> CostModel;
diff --git a/ydb/core/blobstorage/storagepoolmon/storagepool_counters.h b/ydb/core/blobstorage/storagepoolmon/storagepool_counters.h
index de923b6bb7..b80296a62a 100644
--- a/ydb/core/blobstorage/storagepoolmon/storagepool_counters.h
+++ b/ydb/core/blobstorage/storagepoolmon/storagepool_counters.h
@@ -187,10 +187,7 @@ public:
         }
 
         // request cost counters
-        {
-            auto group = PoolGroup->GetSubgroup("subsystem", "cost");
-            DSProxyDiskCostCounter = group->GetCounter("DSProxyDiskCostNs", true);
-        }
+        DSProxyDiskCostCounter = PoolGroup->GetCounter("DSProxyDiskCostNs", true);
     }
 
 public:
diff --git a/ydb/core/blobstorage/ut_blobstorage/CMakeLists.darwin-x86_64.txt b/ydb/core/blobstorage/ut_blobstorage/CMakeLists.darwin-x86_64.txt
index 0ae1ccfd5a..5f94d3258c 100644
--- a/ydb/core/blobstorage/ut_blobstorage/CMakeLists.darwin-x86_64.txt
+++ b/ydb/core/blobstorage/ut_blobstorage/CMakeLists.darwin-x86_64.txt
@@ -49,6 +49,7 @@ target_sources(ydb-core-blobstorage-ut_blobstorage PRIVATE
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/incorrect_queries.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/main.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/mirror3of4.cpp
+  ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/monitoring.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/recovery.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/sanitize_groups.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/scrub_fast.cpp
diff --git a/ydb/core/blobstorage/ut_blobstorage/CMakeLists.linux-aarch64.txt b/ydb/core/blobstorage/ut_blobstorage/CMakeLists.linux-aarch64.txt
index 0507f73ff2..b369f934b0 100644
--- a/ydb/core/blobstorage/ut_blobstorage/CMakeLists.linux-aarch64.txt
+++ b/ydb/core/blobstorage/ut_blobstorage/CMakeLists.linux-aarch64.txt
@@ -52,6 +52,7 @@ target_sources(ydb-core-blobstorage-ut_blobstorage PRIVATE
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/incorrect_queries.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/main.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/mirror3of4.cpp
+  ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/monitoring.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/recovery.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/sanitize_groups.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/scrub_fast.cpp
diff --git a/ydb/core/blobstorage/ut_blobstorage/CMakeLists.linux-x86_64.txt b/ydb/core/blobstorage/ut_blobstorage/CMakeLists.linux-x86_64.txt
index d49a3b9279..02389cc29f 100644
--- a/ydb/core/blobstorage/ut_blobstorage/CMakeLists.linux-x86_64.txt
+++ b/ydb/core/blobstorage/ut_blobstorage/CMakeLists.linux-x86_64.txt
@@ -53,6 +53,7 @@ target_sources(ydb-core-blobstorage-ut_blobstorage PRIVATE
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/incorrect_queries.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/main.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/mirror3of4.cpp
+  ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/monitoring.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/recovery.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/sanitize_groups.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/scrub_fast.cpp
diff --git a/ydb/core/blobstorage/ut_blobstorage/CMakeLists.windows-x86_64.txt b/ydb/core/blobstorage/ut_blobstorage/CMakeLists.windows-x86_64.txt
index d35c83a40f..984f0184b1 100644
--- a/ydb/core/blobstorage/ut_blobstorage/CMakeLists.windows-x86_64.txt
+++ b/ydb/core/blobstorage/ut_blobstorage/CMakeLists.windows-x86_64.txt
@@ -42,6 +42,7 @@ target_sources(ydb-core-blobstorage-ut_blobstorage PRIVATE
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/incorrect_queries.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/main.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/mirror3of4.cpp
+  ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/monitoring.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/recovery.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/sanitize_groups.cpp
   ${CMAKE_SOURCE_DIR}/ydb/core/blobstorage/ut_blobstorage/scrub_fast.cpp
diff --git a/ydb/core/blobstorage/ut_blobstorage/lib/env.h b/ydb/core/blobstorage/ut_blobstorage/lib/env.h
index 6f454f28aa..309cb02df4 100644
--- a/ydb/core/blobstorage/ut_blobstorage/lib/env.h
+++ b/ydb/core/blobstorage/ut_blobstorage/lib/env.h
@@ -273,6 +273,8 @@ struct TEnvironmentSetup {
         if (printActorNamesAndEvents) {
             Runtime->SetOwnLogPriority(NActors::NLog::EPrio::Info);
         }
+
+        // Runtime->SetLogPriority(NKikimrServices::BS_REQUEST_COST, NLog::PRI_TRACE);
     }
 
     void SetupStaticStorage() {
diff --git a/ydb/core/blobstorage/ut_blobstorage/monitoring.cpp b/ydb/core/blobstorage/ut_blobstorage/monitoring.cpp
new file mode 100644
index 0000000000..e96a088a0e
--- /dev/null
+++ b/ydb/core/blobstorage/ut_blobstorage/monitoring.cpp
@@ -0,0 +1,294 @@
+#include <ydb/core/blobstorage/ut_blobstorage/lib/env.h>
+#include <ydb/core/blobstorage/groupinfo/blobstorage_groupinfo.h>
+
+constexpr bool VERBOSE = true;
+
+TString MakeData(ui32 dataSize) {
+    TString data(dataSize, '\0');
+    for (ui32 i = 0; i < dataSize; ++i) {
+        data[i] = 'A' + (i % 26);
+    }
+    return data;
+}
+
+class TInflightActor : public TActorBootstrapped<TInflightActor> {
+public:
+    TInflightActor(ui32 requests, ui32 inflight)
+        : RequestCount(requests)
+        , RequestInflight(inflight)
+    {}
+
+    virtual ~TInflightActor() = default;
+
+    void SetGroupId(ui32 groupId) {
+        GroupId = groupId;
+    }
+    void Bootstrap(const TActorContext &ctx) {
+        BootstrapImpl(ctx);
+    }
+
+protected:
+    void SendRequests() {
+        while (RequestInflight > 0 && RequestCount > 0) {
+            RequestInflight--;
+            RequestCount--;
+            SendRequest();
+        }
+    }
+
+    void HandleReply(NKikimrProto::EReplyStatus status) {
+        if (status == NKikimrProto::OK) {
+            OKs++;
+        } else {
+            Fails++;
+        }
+        ++RequestInflight;
+        SendRequests();
+    }
+
+    virtual void BootstrapImpl(const TActorContext &ctx) = 0;
+    virtual void SendRequest() = 0;
+
+protected:
+    ui32 RequestCount;
+    ui32 RequestInflight;
+    ui32 GroupId;
+
+public:
+    ui32 OKs = 0;
+    ui32 Fails = 0;
+};
+
+void Test(const TBlobStorageGroupInfo::TTopology& topology, TInflightActor* actor) {
+    const ui32 groupSize = topology.TotalVDisks;
+    const auto& groupErasure = topology.GType;
+    TEnvironmentSetup env{{
+        .NodeCount = groupSize,
+        .Erasure = groupErasure,
+    }};
+
+    env.CreateBoxAndPool(1, 1);
+    env.Sim(TDuration::Seconds(30));
+
+    NKikimrBlobStorage::TConfigRequest request;
+    request.AddCommand()->MutableQueryBaseConfig();
+    auto response = env.Invoke(request);
+
+    const auto& baseConfig = response.GetStatus(0).GetBaseConfig();
+    UNIT_ASSERT_VALUES_EQUAL(baseConfig.GroupSize(), 1);
+    ui32 groupId = baseConfig.GetGroup(0).GetGroupId();
+    std::vector<ui32> pdiskIds(groupSize);
+    for (const auto& vslot : baseConfig.GetVSlot()) {
+        const auto& vslotId = vslot.GetVSlotId();
+        ui32 orderNumber = topology.GetOrderNumber(TVDiskIdShort(vslot.GetFailRealmIdx(), vslot.GetFailDomainIdx(), vslot.GetVDiskIdx()));
+        if (vslot.GetGroupId() == groupId) {
+            pdiskIds[orderNumber] = vslotId.GetPDiskId();
+        }
+    }
+
+    ui64 dsproxyCost = 0;
+    ui64 vdiskCost = 0;
+    ui64 hugePuts = 0;
+    ui64 logPuts = 0;
+
+    auto* appData = env.Runtime->GetAppData();
+    Y_VERIFY(appData);
+
+    auto vdisksTotal = [&](TString subsystem, TString counter, bool derivative = false) {
+        ui64 ctr = 0;
+        for (ui32 i = 0; i < groupSize; ++i) {
+            ctr += GetServiceCounters(appData->Counters, "vdisks")->
+                    GetSubgroup("storagePool", env.StoragePoolName)->
+                    GetSubgroup("group", std::to_string(groupId))->
+                    GetSubgroup("orderNumber", "0" + std::to_string(i))->
+                    GetSubgroup("pdisk", "00000" + std::to_string(pdiskIds[i]))->
+                    GetSubgroup("media", "rot")->
+                    GetSubgroup("subsystem", subsystem)->
+                    GetCounter(counter, derivative)->Val();
+        }
+        return ctr;
+    };
+
+    auto updateCounters = [&]() {
+        dsproxyCost = GetServiceCounters(appData->Counters, "dsproxynode")->
+                GetSubgroup("subsystem", "request")->
+                GetSubgroup("storagePool", env.StoragePoolName)->
+                GetCounter("DSProxyDiskCostNs")->Val();
+        vdiskCost = vdisksTotal("outofspace", "EstimatedDiskTimeConsumptionNs");
+        logPuts = vdisksTotal("skeletonfront", "SkeletonFront/LogPuts/CostProcessed");
+        hugePuts = vdisksTotal("skeletonfront", "SkeletonFront/HugePutsForeground/CostProcessed");
+    };
+
+    updateCounters();
+    UNIT_ASSERT_VALUES_EQUAL(dsproxyCost, vdiskCost);
+    
+    actor->SetGroupId(groupId);
+    env.Runtime->Register(actor, 1);
+    env.Sim(TDuration::Minutes(15));
+
+    updateCounters();
+
+    TStringStream str;
+    double proportion = 1. * dsproxyCost / vdiskCost;
+    i64 diff = (i64)dsproxyCost - vdiskCost;
+    str << "OKs# " << actor->OKs << ", Fails# " << actor->Fails << ", Cost on dsproxy# "
+            << dsproxyCost << ", Cost on vdisks# " << vdiskCost << ", proportion# " << proportion
+            << " diff# " << diff << " hugePuts# " << hugePuts << " logPuts# " << logPuts;
+
+    if constexpr(VERBOSE) {
+        Cerr << str.Str() << Endl;
+        // env.Runtime->GetAppData()->Counters->OutputPlainText(Cerr);
+    }
+    UNIT_ASSERT_VALUES_EQUAL_C(dsproxyCost, vdiskCost, str.Str());
+}
+
+class TInflightActorPut : public TInflightActor {
+public:
+    TInflightActorPut(ui32 requests, ui32 inflight, ui32 dataSize = 1024)
+        : TInflightActor(requests, inflight)
+        , DataSize(dataSize)
+    {}
+
+    STRICT_STFUNC(StateWork,
+        cFunc(TEvBlobStorage::TEvStatusResult::EventType, SendRequests);
+        hFunc(TEvBlobStorage::TEvPutResult, Handle);
+    )
+
+    virtual void BootstrapImpl(const TActorContext&/* ctx*/) override {
+        // dummy request to establish the session
+        auto ev = new TEvBlobStorage::TEvStatus(TInstant::Max());
+        SendToBSProxy(SelfId(), GroupId, ev, 0);
+        Become(&TInflightActorPut::StateWork);
+    }
+
+protected:
+    virtual void SendRequest() override {
+        TString data = MakeData(DataSize);
+        auto ev = new TEvBlobStorage::TEvPut(TLogoBlobID(1, 1, 1, 10, DataSize, RequestCount + 1),
+                data, TInstant::Max(), NKikimrBlobStorage::UserData);
+        SendToBSProxy(SelfId(), GroupId, ev, 0);
+    }
+
+    void Handle(TEvBlobStorage::TEvPutResult::TPtr res) {
+        HandleReply(res->Get()->Status);
+    }
+
+private:
+    std::string Data;
+    ui32 DataSize;
+};
+
+#define MAKE_TEST(erasure, requestType, requests, inflight)                         \
+Y_UNIT_TEST(Test##requestType##erasure##Requests##requests##Inflight##inflight) {   \
+    auto groupType = TBlobStorageGroupType::Erasure##erasure;                       \
+    ui32 realms = (groupType == TBlobStorageGroupType::ErasureMirror3dc) ? 3 : 1;   \
+    ui32 domains = (groupType == TBlobStorageGroupType::ErasureMirror3dc) ? 3 : 8;  \
+    TBlobStorageGroupInfo::TTopology topology(groupType, realms, domains, 1, true); \
+    auto actor = new TInflightActor##requestType(requests, inflight);               \
+    Test(topology, actor);                                                          \
+}
+
+#define MAKE_TEST_W_DATASIZE(erasure, requestType, requests, inflight, dataSize)                        \
+Y_UNIT_TEST(Test##requestType##erasure##Requests##requests##Inflight##inflight##BlobSize##dataSize) {   \
+    auto groupType = TBlobStorageGroupType::Erasure##erasure;                                           \
+    ui32 realms = (groupType == TBlobStorageGroupType::ErasureMirror3dc) ? 3 : 1;                       \
+    ui32 domains = (groupType == TBlobStorageGroupType::ErasureMirror3dc) ? 3 : 8;                      \
+    TBlobStorageGroupInfo::TTopology topology(groupType, realms, domains, 1, true);                     \
+    auto actor = new TInflightActor##requestType(requests, inflight, dataSize);                         \
+    Test(topology, actor);                                                                              \
+}
+
+class TInflightActorGet : public TInflightActor {
+public:
+    TInflightActorGet(ui32 requests, ui32 inflight, ui32 dataSize = 1024)
+        : TInflightActor(requests, inflight)
+        , DataSize(dataSize)
+    {}
+
+    STRICT_STFUNC(StateWork,
+        cFunc(TEvBlobStorage::TEvPutResult::EventType, SendRequests);
+        hFunc(TEvBlobStorage::TEvGetResult, Handle);
+    )
+
+    virtual void BootstrapImpl(const TActorContext&/* ctx*/) override {
+        TString data = MakeData(DataSize);
+        BlobId = TLogoBlobID(1, 1, 1, 10, DataSize, 1);
+        auto ev = new TEvBlobStorage::TEvPut(BlobId, data, TInstant::Max());
+        SendToBSProxy(SelfId(), GroupId, ev, 0);
+        Become(&TInflightActorGet::StateWork);
+    }
+
+protected:
+    virtual void SendRequest() override {
+        auto ev = new TEvBlobStorage::TEvGet(BlobId, 0, 10, TInstant::Max(), NKikimrBlobStorage::EGetHandleClass::FastRead);
+        SendToBSProxy(SelfId(), GroupId, ev, 0);
+    }
+
+    void Handle(TEvBlobStorage::TEvGetResult::TPtr res) {
+        HandleReply(res->Get()->Status);
+    }
+
+private:
+    TLogoBlobID BlobId;
+    std::string Data;
+    ui32 DataSize;
+};
+
+Y_UNIT_TEST_SUITE(CostMetricsPutMirror3dc) {
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 1, 1, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 10, 1, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 10000, 1, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 2, 2, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 10, 10, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 100, 10, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 10000, 1000, 1000);
+}
+
+Y_UNIT_TEST_SUITE(CostMetricsPutBlock4Plus2) {
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Put, 1, 1, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Put, 10, 1, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Put, 10000, 1, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Put, 2, 2, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Put, 10, 10, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Put, 100, 10, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Put, 10000, 1000, 1000);
+}
+
+Y_UNIT_TEST_SUITE(CostMetricsPutHugeMirror3dc) {
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 1, 1, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 10, 1, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 100, 1, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 2, 2, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 10, 10, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Put, 100, 10, 2000000);
+}
+
+Y_UNIT_TEST_SUITE(CostMetricsGetMirror3dc) {
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 1, 1, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 10, 1, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 10000, 1, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 2, 2, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 10, 10, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 100, 10, 1000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 10000, 1000, 1000);
+}
+    
+Y_UNIT_TEST_SUITE(CostMetricsGetBlock4Plus2) {
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Get, 1, 1, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Get, 10, 1, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Get, 10000, 1, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Get, 2, 2, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Get, 10, 10, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Get, 100, 10, 1000);
+    MAKE_TEST_W_DATASIZE(4Plus2Block, Get, 10000, 1000, 1000);
+}
+
+Y_UNIT_TEST_SUITE(CostMetricsGetHugeMirror3dc) {
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 1, 1, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 10, 1, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 100, 1, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 2, 2, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 10, 10, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 100, 10, 2000000);
+    MAKE_TEST_W_DATASIZE(Mirror3dc, Get, 10000, 100, 2000000);
+}
diff --git a/ydb/core/blobstorage/ut_blobstorage/ya.make b/ydb/core/blobstorage/ut_blobstorage/ya.make
index a8b6ccd8e4..ce95915d31 100644
--- a/ydb/core/blobstorage/ut_blobstorage/ya.make
+++ b/ydb/core/blobstorage/ut_blobstorage/ya.make
@@ -24,6 +24,7 @@ SRCS(
     incorrect_queries.cpp
     main.cpp
     mirror3of4.cpp
+    monitoring.cpp
     recovery.cpp
     sanitize_groups.cpp
     scrub_fast.cpp
diff --git a/ydb/core/blobstorage/vdisk/skeleton/blobstorage_skeletonfront.cpp b/ydb/core/blobstorage/vdisk/skeleton/blobstorage_skeletonfront.cpp
index 7076f5b16b..98d4771ab7 100644
--- a/ydb/core/blobstorage/vdisk/skeleton/blobstorage_skeletonfront.cpp
+++ b/ydb/core/blobstorage/vdisk/skeleton/blobstorage_skeletonfront.cpp
@@ -1193,7 +1193,10 @@ namespace NKikimr {
                    VCtx->VDiskLogPrefix.data(), msgName, NKikimrBlobStorage::EVDiskInternalQueueId_Name(intQueueId).data(),
                    NKikimrBlobStorage::EVDiskQueueId_Name(extQueueId).data());
 
-            DskOutOfSpaceGroup.EstimatedDiskTimeConsumptionNs() += cost;
+            LOG_TRACE_S(TActivationContext::AsActorContext(), NKikimrServices::BS_REQUEST_COST,
+                        "SkeletonFront Request Type# " << TypeName(*ev) << " Cost# " << cost <<
+                        " Sender# " << ev->Sender.ToString());
+
             TExtQueueClass &extQueue = GetExtQueue(extQueueId);
             NBackpressure::TQueueClientId clientId(msgQoS);
             std::unique_ptr<IEventHandle> event = extQueue.Enqueue(ctx, std::unique_ptr<IEventHandle>(
@@ -1207,6 +1210,7 @@ namespace NKikimr {
                 // good, enqueue it in intQueue
                 intQueue.Enqueue(ctx, recByteSize, std::move(event), msgId, cost,
                         deadline, extQueueId, *this, clientId, std::move(trace));
+                DskOutOfSpaceGroup.EstimatedDiskTimeConsumptionNs() += cost;
             }
 
             Sanitize(ctx);
diff --git a/ydb/library/services/services.proto b/ydb/library/services/services.proto
index 0f6466edb9..6295ce7a11 100644
--- a/ydb/library/services/services.proto
+++ b/ydb/library/services/services.proto
@@ -377,6 +377,9 @@ enum EServiceKikimr {
     OBJECTS_MONITORING = 2300;
 
     STATISTICS = 2400;
+
+    // Distributed storage debugging
+    BS_REQUEST_COST = 2500;
 };
 
 message TActivity {