issue-1146: decrease verbosity of loading nodes and noderefs and add …

…option to space out this loading over time (#2899)

cloud/filestore/config/storage.proto

@@ -514,4 +514,7 @@ message TStorageConfig
     optional uint64 MixedBlocksOffloadedRangesCapacity = 415;
 
     optional bool YdbViewerServiceEnabled = 416;
+
+    // During the InMemoryIndexCache load, the time between the batches loading
+    optional uint32 InMemoryIndexCacheLoadSchedulePeriod = 417;  // in ms
 }

cloud/filestore/libs/storage/core/config.cpp

@@ -219,7 +219,10 @@ using TAliases = NProto::TStorageConfig::TFilestoreAliases;
     xxx(InMemoryIndexCacheNodeRefsCapacity,             ui64,       0         )\
     xxx(InMemoryIndexCacheNodesToNodeRefsCapacityRatio, ui64,       0         )\
     xxx(InMemoryIndexCacheLoadOnTabletStart,            bool,       false     )\
-    xxx(InMemoryIndexCacheLoadOnTabletStartRowsPerTx,   ui64,       1000000   )\
+    xxx(InMemoryIndexCacheLoadOnTabletStartRowsPerTx,   ui64,       1000      )\
+    xxx(InMemoryIndexCacheLoadSchedulePeriod,                                  \
+        TDuration,                                                             \
+        TDuration::Seconds(0)                                                 )\
                                                                                \
     xxx(NonNetworkMetricsBalancingFactor,               ui32,      1_KB       )\
                                                                                \

cloud/filestore/libs/storage/core/config.h

@@ -241,6 +241,7 @@ class TStorageConfig
     ui64 GetInMemoryIndexCacheNodesToNodeRefsCapacityRatio() const;
     bool GetInMemoryIndexCacheLoadOnTabletStart() const;
     ui64 GetInMemoryIndexCacheLoadOnTabletStartRowsPerTx() const;
+    TDuration GetInMemoryIndexCacheLoadSchedulePeriod() const;
 
     bool GetAsyncDestroyHandleEnabled() const;
     TDuration GetAsyncHandleOperationPeriod() const;

cloud/filestore/libs/storage/tablet/tablet_actor_adddata.cpp

@@ -296,8 +296,6 @@ void TIndexTabletActor::HandleGenerateBlobIds(
         offset += length;
     }
 
-    // TODO(debnatkh): Throttling
-
     response->Record.SetCommitId(commitId);
 
     Metrics.GenerateBlobIds.Count.fetch_add(1, std::memory_order_relaxed);

cloud/filestore/libs/storage/tablet/tablet_actor_loadstate.cpp

@@ -313,21 +313,44 @@ void TIndexTabletActor::CompleteTx_LoadState(
     {
         const ui64 maxRows =
             Config->GetInMemoryIndexCacheLoadOnTabletStartRowsPerTx();
+        const TDuration schedulePeriod =
+            Config->GetInMemoryIndexCacheLoadSchedulePeriod();
 
         // If necessary, code can iteratively call ReadNodeRefs for all nodes.
         // This will populate cache with node refs and allow us to perform
         // ListNodes using in-memory index state by knowing that the nodeRefs
         // cache is exhaustive
+        LOG_INFO(
+            ctx,
+            TFileStoreComponents::TABLET,
+            "%s LoadNodeRefs started (maxNodeRefs: %lu, period: %s)",
+            LogTag.c_str(),
+            maxRows,
+            schedulePeriod.ToString().c_str());
         ctx.Send(
             SelfId(),
-            new TEvIndexTabletPrivate::TEvLoadNodeRefsRequest(0, "", maxRows));
+            new TEvIndexTabletPrivate::TEvLoadNodeRefsRequest(
+                0,
+                "",
+                maxRows,
+                schedulePeriod));
 
         // Same logic is performed for batch loading nodes as well. The only
         // difference is that we do not need to keep track of the exhaustiveness
         // of the cache
+        LOG_INFO(
+            ctx,
+            TFileStoreComponents::TABLET,
+            "%s LoadNodes started (maxNodes: %lu, period: %s)",
+            LogTag.c_str(),
+            maxRows,
+            schedulePeriod.ToString().c_str());
         ctx.Send(
             SelfId(),
-            new TEvIndexTabletPrivate::TEvLoadNodesRequest(0, maxRows));
+            new TEvIndexTabletPrivate::TEvLoadNodesRequest(
+                0,
+                maxRows,
+                schedulePeriod));
     }
 
     ScheduleSyncSessions(ctx);

cloud/filestore/libs/storage/tablet/tablet_actor_loadstate_noderefs.cpp

@@ -10,7 +10,7 @@ bool TIndexTabletActor::ValidateTx_LoadNodeRefs(
     const TActorContext& ctx,
     TTxIndexTablet::TLoadNodeRefs& args)
 {
-    LOG_INFO(
+    LOG_DEBUG(
         ctx,
         TFileStoreComponents::TABLET,
         "%s LoadingNodeRefs (nodeId: %lu, name: %s, maxNodeRefs: %lu)",
@@ -36,7 +36,7 @@ bool TIndexTabletActor::PrepareTx_LoadNodeRefs(
         args.NextNodeId,
         args.NextCookie);
 
-    LOG_INFO(
+    LOG_DEBUG(
         ctx,
         TFileStoreComponents::TABLET,
         "%s LoadingNodeRefs (nodeId: %lu, name: %s, maxNodeRefs: %lu), read "
@@ -55,7 +55,7 @@ void TIndexTabletActor::CompleteTx_LoadNodeRefs(
     const TActorContext& ctx,
     TTxIndexTablet::TLoadNodeRefs& args)
 {
-    LOG_INFO(
+    LOG_DEBUG(
         ctx,
         TFileStoreComponents::TABLET,
         "%s LoadNodeRefs iteration completed, next nodeId: %lu, next cookie: "
@@ -65,12 +65,13 @@ void TIndexTabletActor::CompleteTx_LoadNodeRefs(
         args.NextCookie.c_str());
 
     if (args.NextCookie || args.NextNodeId) {
-        ctx.Send(
-            SelfId(),
+        ctx.Schedule(
+            args.SchedulePeriod,
             new TEvIndexTabletPrivate::TEvLoadNodeRefsRequest(
                 args.NextNodeId,
                 args.NextCookie,
-                args.MaxNodeRefs));
+                args.MaxNodeRefs,
+                args.SchedulePeriod));
     } else {
         LOG_INFO(
             ctx,
@@ -90,7 +91,7 @@ void TIndexTabletActor::HandleLoadNodeRefsRequest(
 {
     auto* msg = ev->Get();
 
-    LOG_INFO(
+    LOG_DEBUG(
         ctx,
         TFileStoreComponents::TABLET,
         "%s LoadNodeRefs iteration started (nodeId: %lu, name: %s, "
@@ -109,7 +110,8 @@ void TIndexTabletActor::HandleLoadNodeRefsRequest(
         std::move(requestInfo),
         msg->NodeId,
         msg->Cookie,
-        msg->MaxNodeRefs);
+        msg->MaxNodeRefs,
+        msg->SchedulePeriod);
 }
 
 }   // namespace NCloud::NFileStore::NStorage

cloud/filestore/libs/storage/tablet/tablet_actor_loadstate_nodes.cpp

@@ -10,7 +10,7 @@ bool TIndexTabletActor::ValidateTx_LoadNodes(
     const TActorContext& ctx,
     TTxIndexTablet::TLoadNodes& args)
 {
-    LOG_INFO(
+    LOG_DEBUG(
         ctx,
         TFileStoreComponents::TABLET,
         "%s LoadingNodes (nodeId: %lu, maxNodes: %lu)",
@@ -31,7 +31,7 @@ bool TIndexTabletActor::PrepareTx_LoadNodes(
     bool ready =
         db.ReadNodes(args.NodeId, args.MaxNodes, args.NextNodeId, nodes);
 
-    LOG_INFO(
+    LOG_DEBUG(
         ctx,
         TFileStoreComponents::TABLET,
         "%s LoadingNodes (nodeId: %lu, maxNodes: %lu), read %lu nodes: %s",
@@ -48,19 +48,20 @@ void TIndexTabletActor::CompleteTx_LoadNodes(
     const TActorContext& ctx,
     TTxIndexTablet::TLoadNodes& args)
 {
-    LOG_INFO(
+    LOG_DEBUG(
         ctx,
         TFileStoreComponents::TABLET,
         "%s LoadNodes iteration completed, next nodeId: %lu",
         LogTag.c_str(),
         args.NextNodeId);
 
     if (args.NextNodeId) {
-        ctx.Send(
-            SelfId(),
+        ctx.Schedule(
+            args.SchedulePeriod,
             new TEvIndexTabletPrivate::TEvLoadNodesRequest(
                 args.NextNodeId,
-                args.MaxNodes));
+                args.MaxNodes,
+                args.SchedulePeriod));
     } else {
         LOG_INFO(
             ctx,
@@ -78,7 +79,7 @@ void TIndexTabletActor::HandleLoadNodesRequest(
 {
     auto* msg = ev->Get();
 
-    LOG_INFO(
+    LOG_DEBUG(
         ctx,
         TFileStoreComponents::TABLET,
         "%s LoadNodes iteration started (nodeId: %lu, maxNodes: %lu)",
@@ -94,7 +95,8 @@ void TIndexTabletActor::HandleLoadNodesRequest(
         ctx,
         std::move(requestInfo),
         msg->NodeId,
-        msg->MaxNodes);
+        msg->MaxNodes,
+        msg->SchedulePeriod);
 }
 
 }   // namespace NCloud::NFileStore::NStorage

cloud/filestore/libs/storage/tablet/tablet_private.h

@@ -534,14 +534,17 @@ struct TEvIndexTabletPrivate
         const ui64 NodeId;
         const TString Cookie;
         const ui32 MaxNodeRefs;
+        const TDuration SchedulePeriod;
 
         TLoadNodeRefsRequest(
                 ui64 nodeId,
                 TString cookie,
-                ui32 maxNodeRefs)
+                ui32 maxNodeRefs,
+                TDuration schedulePeriod)
             : NodeId(nodeId)
             , Cookie(std::move(cookie))
             , MaxNodeRefs(maxNodeRefs)
+            , SchedulePeriod(schedulePeriod)
         {}
     };
 
@@ -553,12 +556,15 @@ struct TEvIndexTabletPrivate
     {
         const ui64 NodeId;
         const ui32 MaxNodes;
+        const TDuration SchedulePeriod;
 
         TLoadNodesRequest(
                 ui64 nodeId,
-                ui32 maxNodes)
+                ui32 maxNodes,
+                TDuration schedulePeriod)
             : NodeId(nodeId)
             , MaxNodes(maxNodes)
+            , SchedulePeriod(schedulePeriod)
         {}
     };
 

cloud/filestore/libs/storage/tablet/tablet_tx.h

@@ -2256,6 +2256,7 @@ struct TTxIndexTablet
         const ui64 NodeId;
         const TString Cookie;
         const ui64 MaxNodeRefs;
+        const TDuration SchedulePeriod;
 
         ui64 NextNodeId = 0;
         TString NextCookie;
@@ -2264,11 +2265,13 @@ struct TTxIndexTablet
                 TRequestInfoPtr requestInfo,
                 ui64 nodeId,
                 TString cookie,
-                ui64 maxNodeRefs)
+                ui64 maxNodeRefs,
+                TDuration schedulePeriod)
             : RequestInfo(std::move(requestInfo))
             , NodeId(nodeId)
             , Cookie(std::move(cookie))
             , MaxNodeRefs(maxNodeRefs)
+            , SchedulePeriod(schedulePeriod)
         {}
 
         void Clear()
@@ -2289,16 +2292,19 @@ struct TTxIndexTablet
         const TRequestInfoPtr RequestInfo;
         const ui64 NodeId;
         const ui64 MaxNodes;
+        const TDuration SchedulePeriod;
 
         ui64 NextNodeId = 0;
 
         TLoadNodes(
                 TRequestInfoPtr requestInfo,
                 ui64 nodeId,
-                ui64 maxNodes)
+                ui64 maxNodes,
+                TDuration schedulePeriod)
             : RequestInfo(std::move(requestInfo))
             , NodeId(nodeId)
             , MaxNodes(maxNodes)
+            , SchedulePeriod(schedulePeriod)
         {}
 
         void Clear()

cloud/filestore/libs/storage/tablet/tablet_ut_cache.cpp

@@ -920,6 +920,8 @@ Y_UNIT_TEST_SUITE(TIndexTabletTest_NodesCache)
         storageConfig.SetInMemoryIndexCacheNodeRefsCapacity(100);
         storageConfig.SetInMemoryIndexCacheLoadOnTabletStart(true);
         storageConfig.SetInMemoryIndexCacheLoadOnTabletStartRowsPerTx(1);
+        storageConfig.SetInMemoryIndexCacheLoadSchedulePeriod(
+            TDuration::Seconds(1).MilliSeconds());
         TTestEnv env({}, storageConfig);
         env.CreateSubDomain("nfs");
 
@@ -930,22 +932,25 @@ Y_UNIT_TEST_SUITE(TIndexTabletTest_NodesCache)
         tablet.InitSession("client", "session");
 
         tablet.CreateNode(TCreateNodeArgs::File(RootNodeId, "test1"));
-        tablet.CreateNode(TCreateNodeArgs::File(RootNodeId, "test2"));
 
         env.GetRuntime().ClearCounters();
         tablet.RebootTablet();
+
+        for (int i = 0; i < 10; ++i) {
+            tablet.AdvanceTime(TDuration::Seconds(1));
+            env.GetRuntime().DispatchEvents({}, TDuration::Seconds(1));
+        }
+
         tablet.InitSession("client", "session");
 
-        // It will take 2 iterations to load all the nodeRefs (root -> test1 and
-        // root -> test2)
+        // It will take 1 iteration to load all the nodeRefs (root -> test)1
         UNIT_ASSERT_VALUES_EQUAL(
-            2,
+            1,
             env.GetRuntime().GetCounter(
                 TEvIndexTabletPrivate::EEvents::EvLoadNodeRefs));
-        // It also will take 3 iterations to load all the nodes (root, test1 and
-        // test2)
+        // It also will take 2 iterations to load all the nodes (root and test1)
         UNIT_ASSERT_VALUES_EQUAL(
-            3,
+            2,
             env.GetRuntime().GetCounter(
                 TEvIndexTabletPrivate::EEvents::EvLoadNodes));
 
@@ -954,7 +959,7 @@ Y_UNIT_TEST_SUITE(TIndexTabletTest_NodesCache)
         // The noderefs cache is exhaustive thus list nodes should be a cache
         // hit
         UNIT_ASSERT_VALUES_EQUAL(
-            2,
+            1,
             tablet.ListNodes(RootNodeId)->Record.NodesSize());
 
         auto statsAfter = GetTxStats(env, tablet);
@@ -969,28 +974,27 @@ Y_UNIT_TEST_SUITE(TIndexTabletTest_NodesCache)
 
         statsBefore = statsAfter;
 
-        auto id3 =
-            tablet.CreateNode(TCreateNodeArgs::Directory(RootNodeId, "test3"))
+        auto id2 =
+            tablet.CreateNode(TCreateNodeArgs::Directory(RootNodeId, "test2"))
                 ->Record.GetNode()
                 .GetId();
-        tablet.CreateNode(TCreateNodeArgs::File(id3, "test4"));
-        tablet.CreateNode(TCreateNodeArgs::File(id3, "test5"));
-        tablet.CreateNode(TCreateNodeArgs::File(id3, "test6"));
+        tablet.CreateNode(TCreateNodeArgs::File(id2, "test3"));
+        tablet.CreateNode(TCreateNodeArgs::File(id2, "test4"));
+        tablet.CreateNode(TCreateNodeArgs::File(id2, "test5"));
 
         /*
         |- test1
         |- test2
-        |- test3
+            |- test3
             |- test4
             |- test5
-            |- test6
         */
 
         // The NodeRefs cache is still exhaustive thus list nodes should be a
         // cache hit
-        UNIT_ASSERT_VALUES_EQUAL(3, tablet.ListNodes(id3)->Record.NodesSize());
+        UNIT_ASSERT_VALUES_EQUAL(3, tablet.ListNodes(id2)->Record.NodesSize());
         UNIT_ASSERT_VALUES_EQUAL(
-            3,
+            2,
             tablet.ListNodes(RootNodeId)->Record.NodesSize());
 
         statsAfter = GetTxStats(env, tablet);