KIKIMR-20154 Add device wait metric

5 files changed, 32 insertions, 5 deletions

diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_blockdevice_async.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_blockdevice_async.cpp
index b3d14725a8..2a1357967e 100644
--- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_blockdevice_async.cpp
+++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_blockdevice_async.cpp
@@ -230,7 +230,11 @@ class TRealBlockDevice : public IBlockDevice {
 
             Device.IncrementMonInFlight(op->GetType(), op->GetSize());
 
-            action->OperationIdx = Device.FlightControl.Schedule();
+            double blockedMs = 0;
+            action->OperationIdx = Device.FlightControl.Schedule(blockedMs);
+
+            *Device.Mon.DeviceWaitTimeMs += blockedMs;
+
             if (action->FlushAction) {
                 action->FlushAction->OperationIdx = action->OperationIdx;
             }
@@ -483,7 +487,7 @@ class TRealBlockDevice : public IBlockDevice {
     ////////////////////////////////////////////////////////
     // TSubmitGetThread
     ////////////////////////////////////////////////////////
-    class TSubmitGetThread : public TSubmitThreadBase{
+    class TSubmitGetThread : public TSubmitThreadBase {
     public:
         TSubmitGetThread(TRealBlockDevice &device)
             : TSubmitThreadBase(device, &ThreadProc, this)
@@ -512,9 +516,20 @@ class TRealBlockDevice : public IBlockDevice {
 
             action->OperationIdx = Device.FlightControl.TrySchedule();
             if (action->OperationIdx == 0) {
+                if (OpScheduleFailedTime == 0) {
+                    // If failed to schedule, remember the time to use it when scheduling succeeds.
+                    OpScheduleFailedTime = HPNow();
+                }
                 return false;
             }
 
+            if (OpScheduleFailedTime != 0) {
+                // Scheduling failed previously, calculate how much time operation had to wait for scheduling.
+                *Device.Mon.DeviceWaitTimeMs += HPMilliSecondsFloat(OpScheduleFailedTime - HPNow());
+
+                OpScheduleFailedTime = 0;
+            }
+
             if (!Device.QuitCounter.Increment()) {
                 Device.FreeOperation(op);
                 TGuard<TMutex> guard(SubmitMtx);
@@ -615,6 +630,8 @@ class TRealBlockDevice : public IBlockDevice {
 
             Y_ABORT_UNLESS(OperationsToBeSubmit.GetWaitingSize() == 0);
         }
+    private:
+        NHPTimer::STime OpScheduleFailedTime = 0;
     };
 
     ////////////////////////////////////////////////////////
diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_mon.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_mon.cpp
index a19631f8ed..0a606fe8f0 100644
--- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_mon.cpp
+++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_mon.cpp
@@ -88,6 +88,7 @@ TPDiskMon::TPDiskMon(const TIntrusivePtr<::NMonitoring::TDynamicCounters>& count
     DeviceSubmitThreadBusyTimeNs = DeviceGroup->GetCounter("DeviceSubmitThreadBusyTimeNs", true);
     DeviceCompletionThreadBusyTimeNs = DeviceGroup->GetCounter("DeviceCompletionThreadBusyTimeNs", true);
     DeviceIoErrors = DeviceGroup->GetCounter("DeviceIoErrors", true);
+    DeviceWaitTimeMs = DeviceGroup->GetCounter("DeviceWaitTimeMs", true);
 
     UpdateDurationTracker.SetCounter(DeviceGroup->GetCounter("PDiskThreadBusyTimeNs", true));
 
diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_mon.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_mon.h
index 3924ec9cd3..621d28c7d7 100644
--- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_mon.h
+++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_mon.h
@@ -549,6 +549,7 @@ struct TPDiskMon {
     ::NMonitoring::TDynamicCounters::TCounterPtr DeviceSubmitThreadBusyTimeNs;
     ::NMonitoring::TDynamicCounters::TCounterPtr DeviceCompletionThreadBusyTimeNs;
     ::NMonitoring::TDynamicCounters::TCounterPtr DeviceIoErrors;
+    ::NMonitoring::TDynamicCounters::TCounterPtr DeviceWaitTimeMs;
 
     // queue subgroup
     TIntrusivePtr<::NMonitoring::TDynamicCounters> QueueGroup;
diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_util_flightcontrol.cpp b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_util_flightcontrol.cpp
index 18ebb67343..5c6d6c728b 100644
--- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_util_flightcontrol.cpp
+++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_util_flightcontrol.cpp
@@ -39,7 +39,8 @@ ui64 TFlightControl::TrySchedule() {
 }
 
 // Blocking Schedule method
-ui64 TFlightControl::Schedule() {
+ui64 TFlightControl::Schedule(double& blockedMs) {
+    NHPTimer::STime beginTime = 0;
     while (true) {
         ui64 idx = TrySchedule();
         if (idx) {
@@ -50,7 +51,11 @@ ui64 TFlightControl::Schedule() {
             if (idx) {
                 return idx;
             }
+            if (beginTime == 0) {
+                beginTime = HPNow();
+            }
             ScheduleCondVar.WaitI(ScheduleMutex);
+            blockedMs = HPMilliSecondsFloat(HPNow() - beginTime);
         }
     }
 }
diff --git a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_util_flightcontrol.h b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_util_flightcontrol.h
index 836ebbb751..8fbb72459a 100644
--- a/ydb/core/blobstorage/pdisk/blobstorage_pdisk_util_flightcontrol.h
+++ b/ydb/core/blobstorage/pdisk/blobstorage_pdisk_util_flightcontrol.h
@@ -1,7 +1,10 @@
 #pragma once
 #include "defs.h"
-#include <util/generic/vector.h>
+#include "blobstorage_pdisk_mon.h"
+
 #include <library/cpp/deprecated/atomic/atomic.h>
+
+#include <util/generic/vector.h>
 #include <util/system/condvar.h>
 
 namespace NKikimr {
@@ -31,7 +34,7 @@ public:
     ui64 TrySchedule();
 
     // Blocking version of TrySchedule
-    ui64 Schedule();
+    ui64 Schedule(double& blockedMs);
 
     void MarkComplete(ui64 idx);
     ui64 FirstIncompleteIdx();