Added counters for local db tables loading times

ydb/core/tx/columnshard/counters/common_data.cpp

@@ -19,4 +19,19 @@ TDataOwnerSignals::TDataOwnerSignals(const TString& module, const TString dataNa
     SkipEraseBytes = GetDeriviative(DataName + "/SkipErase/Bytes");
 }
 
+TLoadTimer::~TLoadTimer() {
+    ui64 duration = (TInstant::Now() - Start).MicroSeconds();
+    if (Failed) {
+        Signals.AddFailedLoadingTime(duration);
+    } else {
+        Signals.AddLoadingTime(duration);
+    }
+    AFL_INFO(NKikimrServices::TX_COLUMNSHARD)(Name, duration);
+}
+
+void TLoadTimer::AddLoadingFail() {
+    Failed = true;
+    Signals.AddLoadingFail();
+}
+
 }

ydb/core/tx/columnshard/counters/common_data.h

@@ -1,6 +1,9 @@
 #pragma once
 #include "common/owner.h"
 
+#include <ydb/library/services/services.pb.h>
+#include <ydb/library/actors/core/log.h>
+
 namespace NKikimr::NColumnShard {
 
 class TDataOwnerSignals: public TCommonCountersOwner {
@@ -53,4 +56,76 @@ class TDataOwnerSignals: public TCommonCountersOwner {
 
 };
 
+class TLoadTimeSignals;
+
+class TLoadTimer {
+private:
+    TLoadTimeSignals& Signals;
+    TInstant Start;
+    TString Name;
+    bool Failed = false;
+
+public:
+    TLoadTimer(TLoadTimeSignals& signals, const TString& name)
+        : Signals(signals)
+        , Name(name)
+    {
+        Start = TInstant::Now();
+    }
+
+    void AddLoadingFail();
+
+    ~TLoadTimer();
+};
+
+class TLoadTimeSignals: public TCommonCountersOwner {
+private:
+    using TBase = TCommonCountersOwner;
+    NMonitoring::TDynamicCounters::TCounterPtr LoadingTimeCounter;
+    NMonitoring::TDynamicCounters::TCounterPtr FailedLoadingTimeCounter;
+    NMonitoring::TDynamicCounters::TCounterPtr LoadingFailCounter;
+
+public:
+    TLoadTimeSignals(const TString& type)
+        : TBase("Startup")
+    {
+        LoadingTimeCounter = TBase::GetValue("Startup/" + type + "LoadingTime");;
+        FailedLoadingTimeCounter = TBase::GetValue("Startup/" + type + "FailedLoadingTime");;
+        LoadingFailCounter = TBase::GetValue("Startup/" + type + "LoadingFailCount");;
+    }
+
+    TLoadTimer StartGuard(const TString& name) {
+        return TLoadTimer(*this, name);
+    }
+
+    void AddLoadingTime(ui64 microSeconds) {
+        LoadingTimeCounter->Add(microSeconds);
+    }
+
+    void AddFailedLoadingTime(ui64 microSeconds) {
+        FailedLoadingTimeCounter->Add(microSeconds);
+    }
+
+    void AddLoadingFail() {
+        LoadingFailCounter->Add(1);
+    }
+};
+
+class TTableLoadTimeCounters {
+public:
+    NColumnShard::TLoadTimeSignals TableLoadTimeCounters;
+    NColumnShard::TLoadTimeSignals SchemaPresetLoadTimeCounters;
+    NColumnShard::TLoadTimeSignals TableVersionsLoadTimeCounters;
+    NColumnShard::TLoadTimeSignals SchemaPresetVersionsLoadTimeCounters;
+
+public:
+    TTableLoadTimeCounters()
+    : TableLoadTimeCounters("Tables")
+    , SchemaPresetLoadTimeCounters("SchemaPreset")
+    , TableVersionsLoadTimeCounters("TableVersionss")
+    , SchemaPresetVersionsLoadTimeCounters("SchemaPresetVersions")
+    {
+    }
+};
+
 }

ydb/core/tx/columnshard/counters/ya.make

@@ -20,6 +20,8 @@ PEERDIR(
     ydb/core/tx/columnshard/counters/aggregation
     ydb/core/tx/columnshard/counters/common
     ydb/core/base
+    ydb/library/actors/core
+    ydb/library/services
 )
 
 GENERATE_ENUM_SERIALIZATION(columnshard.h)

ydb/core/tx/columnshard/engines/column_engine.h

@@ -8,6 +8,7 @@
 #include "scheme/versions/versioned_index.h"
 
 #include <ydb/core/tx/columnshard/common/reverse_accessor.h>
+#include <ydb/core/tx/columnshard/counters/common_data.h>
 
 namespace NKikimr::NColumnShard {
 class TTiersManager;

ydb/core/tx/columnshard/engines/column_engine_logs.cpp

@@ -28,7 +28,10 @@ namespace NKikimr::NOlap {
 
 TColumnEngineForLogs::TColumnEngineForLogs(ui64 tabletId, const std::shared_ptr<IStoragesManager>& storagesManager,
     const TSnapshot& snapshot, const NKikimrSchemeOp::TColumnTableSchema& schema)
-    : GranulesStorage(std::make_shared<TGranulesStorage>(SignalCounters, storagesManager))
+    : PortionsLoadingTimeCounters("PortionsLoading")
+    , ColumnsLoadingTimeCounters("ColumnsLoading")
+    , IndexesLoadingTimeCounters("IndexesLoading")
+    , GranulesStorage(std::make_shared<TGranulesStorage>(SignalCounters, storagesManager))
     , StoragesManager(storagesManager)
     , TabletId(tabletId)
     , LastPortion(0)
@@ -40,7 +43,10 @@ TColumnEngineForLogs::TColumnEngineForLogs(ui64 tabletId, const std::shared_ptr<
 
 TColumnEngineForLogs::TColumnEngineForLogs(ui64 tabletId, const std::shared_ptr<IStoragesManager>& storagesManager,
     const TSnapshot& snapshot, TIndexInfo&& schema)
-    : GranulesStorage(std::make_shared<TGranulesStorage>(SignalCounters, storagesManager))
+    : PortionsLoadingTimeCounters("PortionsLoading")
+    , ColumnsLoadingTimeCounters("ColumnsLoading")
+    , IndexesLoadingTimeCounters("IndexesLoading")
+    , GranulesStorage(std::make_shared<TGranulesStorage>(SignalCounters, storagesManager))
     , StoragesManager(storagesManager)
     , TabletId(tabletId)
     , LastPortion(0)
@@ -208,36 +214,44 @@ bool TColumnEngineForLogs::Load(IDbWrapper& db) {
 bool TColumnEngineForLogs::LoadColumns(IDbWrapper& db) {
     TPortionConstructors constructors;
     {
+        NColumnShard::TLoadTimer timer = PortionsLoadingTimeCounters.StartGuard("portions_loading_time");
         TMemoryProfileGuard g("TTxInit/LoadColumns/Portions");
         if (!db.LoadPortions([&](TPortionInfoConstructor&& portion, const NKikimrTxColumnShard::TIndexPortionMeta& metaProto) {
             const TIndexInfo& indexInfo = portion.GetSchema(VersionedIndex)->GetIndexInfo();
             AFL_VERIFY(portion.MutableMeta().LoadMetadata(metaProto, indexInfo));
             AFL_VERIFY(constructors.AddConstructorVerified(std::move(portion)));
         })) {
+            timer.AddLoadingFail();
             return false;
         }
     }
 
     {
+        NColumnShard::TLoadTimer timer = ColumnsLoadingTimeCounters.StartGuard("columns_loading_time");
         TMemoryProfileGuard g("TTxInit/LoadColumns/Records");
         TPortionInfo::TSchemaCursor schema(VersionedIndex);
         if (!db.LoadColumns([&](TPortionInfoConstructor&& portion, const TColumnChunkLoadContext& loadContext) {
             auto currentSchema = schema.GetSchema(portion);
             auto* constructor = constructors.MergeConstructor(std::move(portion));
             constructor->LoadRecord(currentSchema->GetIndexInfo(), loadContext);
         })) {
+            timer.AddLoadingFail();
             return false;
         }
     }
+
     {
+        NColumnShard::TLoadTimer timer = IndexesLoadingTimeCounters.StartGuard("indexes_loading_time");
         TMemoryProfileGuard g("TTxInit/LoadColumns/Indexes");
         if (!db.LoadIndexes([&](const ui64 pathId, const ui64 portionId, const TIndexChunkLoadContext& loadContext) {
             auto* constructor = constructors.GetConstructorVerified(pathId, portionId);
             constructor->LoadIndex(loadContext);
         })) {
+            timer.AddLoadingFail();
             return false;
         };
     }
+
     {
         TMemoryProfileGuard g("TTxInit/LoadColumns/Constructors");
         for (auto&& [granuleId, pathConstructors] : constructors) {

ydb/core/tx/columnshard/engines/column_engine_logs.h

@@ -11,6 +11,7 @@
 #include <ydb/core/tx/columnshard/columnshard_ttl.h>
 #include <ydb/core/tx/columnshard/common/limits.h>
 #include <ydb/core/tx/columnshard/common/scalars.h>
+#include <ydb/core/tx/columnshard/counters/common_data.h>
 #include <ydb/core/tx/columnshard/counters/engine_logs.h>
 
 namespace NKikimr::NArrow {
@@ -49,6 +50,9 @@ class TColumnEngineForLogs: public IColumnEngine {
 private:
     bool ActualizationStarted = false;
     const NColumnShard::TEngineLogsCounters SignalCounters;
+    NColumnShard::TLoadTimeSignals PortionsLoadingTimeCounters;
+    NColumnShard::TLoadTimeSignals ColumnsLoadingTimeCounters;
+    NColumnShard::TLoadTimeSignals IndexesLoadingTimeCounters;
     std::shared_ptr<TGranulesStorage> GranulesStorage;
     std::shared_ptr<IStoragesManager> StoragesManager;
 

ydb/core/tx/columnshard/engines/insert_table/insert_table.cpp

@@ -125,10 +125,16 @@ bool TInsertTable::Load(NIceDb::TNiceDb& db, IDbWrapper& dbTable, const TInstant
     Loaded = true;
     LastWriteId = (TInsertWriteId)0;
     if (!NColumnShard::Schema::GetSpecialValueOpt(db, NColumnShard::Schema::EValueIds::LastWriteId, LastWriteId)) {
+        LoadCounters.AddLoadingFail();
         return false;
     }
 
-    return dbTable.Load(*this, loadTime);
+    NColumnShard::TLoadTimer timer = LoadCounters.StartGuard("insert_table_loading_time");
+    bool result = dbTable.Load(*this, loadTime);
+    if (!result) {
+        timer.AddLoadingFail();
+    }
+    return result;
 }
 
 std::vector<TCommittedBlob> TInsertTable::Read(ui64 pathId, const std::optional<ui64> lockId, const TSnapshot& reqSnapshot,

ydb/core/tx/columnshard/engines/insert_table/insert_table.h

@@ -6,6 +6,7 @@
 
 #include <ydb/core/tablet_flat/flat_cxx_database.h>
 #include <ydb/core/tablet_flat/tablet_flat_executor.h>
+#include <ydb/core/tx/columnshard/counters/common_data.h>
 #include <ydb/core/tx/columnshard/counters/insert_table.h>
 
 namespace NKikimr::NOlap {
@@ -16,6 +17,12 @@ class TInsertTableAccessor {
 protected:
     TInsertionSummary Summary;
     THashMap<TUnifiedBlobId, ui32> BlobLinks;
+    NColumnShard::TLoadTimeSignals LoadCounters;
+
+    TInsertTableAccessor()
+        : LoadCounters("InsertTable")
+    {
+    }
 
     void AddBlobLink(const TUnifiedBlobId& blobId) {
         ++BlobLinks[blobId];

ydb/core/tx/columnshard/tables_manager.cpp

@@ -46,9 +46,11 @@ bool TTablesManager::FillMonitoringReport(NTabletFlatExecutor::TTransactionConte
 bool TTablesManager::InitFromDB(NIceDb::TNiceDb& db) {
     THashMap<ui32, TSchemaPreset> schemaPresets;
     {
+        TLoadTimer timer = LoadTimeCounters->TableLoadTimeCounters.StartGuard("tables_loading_time");
         TMemoryProfileGuard g("TTablesManager/InitFromDB::Tables");
         auto rowset = db.Table<Schema::TableInfo>().Select();
         if (!rowset.IsReady()) {
+            timer.AddLoadingFail();
             return false;
         }
 
@@ -64,16 +66,19 @@ bool TTablesManager::InitFromDB(NIceDb::TNiceDb& db) {
             AFL_VERIFY(Tables.emplace(table.GetPathId(), std::move(table)).second);
 
             if (!rowset.Next()) {
+                timer.AddLoadingFail();
                 return false;
             }
         }
     }
 
     bool isFakePresetOnly = true;
     {
+        TLoadTimer timer = LoadTimeCounters->SchemaPresetLoadTimeCounters.StartGuard("schema_presets_loading_time");
         TMemoryProfileGuard g("TTablesManager/InitFromDB::SchemaPresets");
         auto rowset = db.Table<Schema::SchemaPresetInfo>().Select();
         if (!rowset.IsReady()) {
+            timer.AddLoadingFail();
             return false;
         }
 
@@ -90,15 +95,18 @@ bool TTablesManager::InitFromDB(NIceDb::TNiceDb& db) {
             AFL_VERIFY(schemaPresets.emplace(preset.GetId(), preset).second);
             AFL_VERIFY(SchemaPresetsIds.emplace(preset.GetId()).second);
             if (!rowset.Next()) {
+                timer.AddLoadingFail();
                 return false;
             }
         }
     }
 
     {
+        TLoadTimer timer = LoadTimeCounters->TableVersionsLoadTimeCounters.StartGuard("table_versions_loading_time");
         TMemoryProfileGuard g("TTablesManager/InitFromDB::Versions");
         auto rowset = db.Table<Schema::TableVersionInfo>().Select();
         if (!rowset.IsReady()) {
+            timer.AddLoadingFail();
             return false;
         }
 
@@ -132,15 +140,18 @@ bool TTablesManager::InitFromDB(NIceDb::TNiceDb& db) {
             }
             table.AddVersion(version);
             if (!rowset.Next()) {
+                timer.AddLoadingFail();
                 return false;
             }
         }
     }
 
     {
+        TLoadTimer timer = LoadTimeCounters->SchemaPresetVersionsLoadTimeCounters.StartGuard("schema_preset_versions_loading_time");
         TMemoryProfileGuard g("TTablesManager/InitFromDB::PresetVersions");
         auto rowset = db.Table<Schema::SchemaPresetVersionInfo>().Select();
         if (!rowset.IsReady()) {
+            timer.AddLoadingFail();
             return false;
         }
 
@@ -156,6 +167,7 @@ bool TTablesManager::InitFromDB(NIceDb::TNiceDb& db) {
             AFL_INFO(NKikimrServices::TX_COLUMNSHARD)("event", "load_preset")("preset_id", id)("snapshot", version)("version", info.HasSchema() ? info.GetSchema().GetVersion() : -1);
             preset.AddVersion(version, info);
             if (!rowset.Next()) {
+                timer.AddLoadingFail();
                 return false;
             }
         }
@@ -340,7 +352,9 @@ void TTablesManager::AddTableVersion(const ui64 pathId, const NOlap::TSnapshot&
 
 TTablesManager::TTablesManager(const std::shared_ptr<NOlap::IStoragesManager>& storagesManager, const ui64 tabletId)
     : StoragesManager(storagesManager)
-    , TabletId(tabletId) {
+    , LoadTimeCounters(std::make_unique<TTableLoadTimeCounters>())
+    , TabletId(tabletId)
+{
 }
 
 bool TTablesManager::TryFinalizeDropPathOnExecute(NTable::TDatabase& dbTable, const ui64 pathId) const {

ydb/core/tx/columnshard/tables_manager.h

@@ -148,6 +148,7 @@ class TTablesManager {
     TTtl Ttl;
     std::unique_ptr<NOlap::IColumnEngine> PrimaryIndex;
     std::shared_ptr<NOlap::IStoragesManager> StoragesManager;
+    std::unique_ptr<TTableLoadTimeCounters> LoadTimeCounters;
     ui64 TabletId = 0;
 public:
     TTablesManager(const std::shared_ptr<NOlap::IStoragesManager>& storagesManager, const ui64 tabletId);