reduce gc log spam (INFO -> DEBUG) (#199)

5 files changed, 57 insertions, 56 deletions

diff --git a/zenserver/cache/structuredcachestore.cpp b/zenserver/cache/structuredcachestore.cpp
index 9773c2ed2..91ae452a8 100644
--- a/zenserver/cache/structuredcachestore.cpp
+++ b/zenserver/cache/structuredcachestore.cpp
@@ -312,7 +312,7 @@ ZenCacheNamespace::GatherReferences(GcContext& GcCtx)
 {
 	Stopwatch  Timer;
 	const auto Guard =
-		MakeGuard([&] { ZEN_INFO("cache gathered all references from '{}' in {}", m_RootDir, NiceTimeSpanMs(Timer.GetElapsedTimeMs())); });
+		MakeGuard([&] { ZEN_DEBUG("cache gathered all references from '{}' in {}", m_RootDir, NiceTimeSpanMs(Timer.GetElapsedTimeMs())); });
 
 	access_tracking::AccessTimes AccessTimes;
 	m_MemLayer.GatherAccessTimes(AccessTimes);
@@ -1204,13 +1204,13 @@ ZenCacheDiskLayer::CacheBucket::GatherReferences(GcContext& GcCtx)
 
 	Stopwatch  TotalTimer;
 	const auto _ = MakeGuard([&] {
-		ZEN_INFO("gathered references from '{}' in {} write lock: {} ({}), read lock: {} ({})",
-				 m_BucketDir / m_BucketName,
-				 NiceTimeSpanMs(TotalTimer.GetElapsedTimeMs()),
-				 NiceLatencyNs(WriteBlockTimeUs),
-				 NiceLatencyNs(WriteBlockLongestTimeUs),
-				 NiceLatencyNs(ReadBlockTimeUs),
-				 NiceLatencyNs(ReadBlockLongestTimeUs));
+		ZEN_DEBUG("gathered references from '{}' in {} write lock: {} ({}), read lock: {} ({})",
+				  m_BucketDir / m_BucketName,
+				  NiceTimeSpanMs(TotalTimer.GetElapsedTimeMs()),
+				  NiceLatencyNs(WriteBlockTimeUs),
+				  NiceLatencyNs(WriteBlockLongestTimeUs),
+				  NiceLatencyNs(ReadBlockTimeUs),
+				  NiceLatencyNs(ReadBlockLongestTimeUs));
 	});
 
 	const GcClock::TimePoint ExpireTime =
@@ -1295,7 +1295,7 @@ ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 {
 	ZEN_TRACE_CPU("Z$::DiskLayer::CacheBucket::CollectGarbage");
 
-	ZEN_INFO("collecting garbage from '{}'", m_BucketDir / m_BucketName);
+	ZEN_DEBUG("collecting garbage from '{}'", m_BucketDir / m_BucketName);
 
 	Stopwatch TotalTimer;
 	uint64_t  WriteBlockTimeUs		  = 0;
@@ -1344,7 +1344,7 @@ ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 	});
 	if (DeleteCacheKeys.empty())
 	{
-		ZEN_INFO("garbage collect SKIPPED, for '{}', no expired cache keys found", m_BucketDir / m_BucketName);
+		ZEN_DEBUG("garbage collect SKIPPED, for '{}', no expired cache keys found", m_BucketDir / m_BucketName);
 		return;
 	}
 
@@ -1361,7 +1361,7 @@ ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 		 });
 		if (m_Index.empty())
 		{
-			ZEN_INFO("garbage collect SKIPPED, for '{}', container is empty", m_BucketDir / m_BucketName);
+			ZEN_DEBUG("garbage collect SKIPPED, for '{}', container is empty", m_BucketDir / m_BucketName);
 			return;
 		}
 		BlockStoreState = m_BlockStore.GetReclaimSnapshotState();
@@ -1506,12 +1506,12 @@ ZenCacheDiskLayer::CacheBucket::CollectGarbage(GcContext& GcCtx)
 	{
 		m_BlockStore.ReclaimSpace(BlockStoreState, ChunkLocations, KeepChunkIndexes, m_PayloadAlignment, true);
 		uint64_t CurrentTotalSize = TotalSize();
-		ZEN_INFO("garbage collect from '{}' DISABLED, found #{} {} chunks of total #{} {}",
-				 m_BucketDir / m_BucketName,
-				 DeleteCount,
-				 0,	 // NiceBytes(TotalSize - NewTotalSize),
-				 CurrentTotalSize,
-				 NiceBytes(CurrentTotalSize));
+		ZEN_DEBUG("garbage collect from '{}' DISABLED, found #{} {} chunks of total #{} {}",
+				  m_BucketDir / m_BucketName,
+				  DeleteCount,
+				  0,  // NiceBytes(TotalSize - NewTotalSize),
+				  CurrentTotalSize,
+				  NiceBytes(CurrentTotalSize));
 		return;
 	}
 
diff --git a/zenserver/projectstore.cpp b/zenserver/projectstore.cpp
index c60d5b405..c3f10c9cd 100644
--- a/zenserver/projectstore.cpp
+++ b/zenserver/projectstore.cpp
@@ -919,8 +919,9 @@ ProjectStore::Project::GatherReferences(GcContext& GcCtx)
 	ZEN_TRACE_CPU("ProjectStore::Project::GatherReferences");
 
 	Stopwatch  Timer;
-	const auto Guard = MakeGuard(
-		[&] { ZEN_INFO("gathered references from project store project {} in {}", Identifier, NiceTimeSpanMs(Timer.GetElapsedTimeMs())); });
+	const auto Guard = MakeGuard([&] {
+		ZEN_DEBUG("gathered references from project store project {} in {}", Identifier, NiceTimeSpanMs(Timer.GetElapsedTimeMs()));
+	});
 
 	// GatherReferences needs to check all existing oplogs
 	std::vector<std::string> OpLogs = ScanForOplogs();
@@ -1084,11 +1085,11 @@ ProjectStore::GatherReferences(GcContext& GcCtx)
 	size_t	   ExpiredProjectCount = 0;
 	Stopwatch  Timer;
 	const auto Guard = MakeGuard([&] {
-		ZEN_INFO("gathered references from '{}' in {}, found {} active projects and {} expired projects",
-				 m_ProjectBasePath.string(),
-				 NiceTimeSpanMs(Timer.GetElapsedTimeMs()),
-				 ProjectCount,
-				 ExpiredProjectCount);
+		ZEN_DEBUG("gathered references from '{}' in {}, found {} active projects and {} expired projects",
+				  m_ProjectBasePath.string(),
+				  NiceTimeSpanMs(Timer.GetElapsedTimeMs()),
+				  ProjectCount,
+				  ExpiredProjectCount);
 	});
 
 	DiscoverProjects();
@@ -1125,11 +1126,11 @@ ProjectStore::CollectGarbage(GcContext& GcCtx)
 
 	Stopwatch				  Timer;
 	const auto				  Guard = MakeGuard([&] {
-		   ZEN_INFO("garbage collect from '{}' DONE after {}, found {} active projects and {} expired projects",
-					m_ProjectBasePath.string(),
-					NiceTimeSpanMs(Timer.GetElapsedTimeMs()),
-					ProjectCount,
-					ExpiredProjectCount);
+		   ZEN_DEBUG("garbage collect from '{}' DONE after {}, found {} active projects and {} expired projects",
+					 m_ProjectBasePath.string(),
+					 NiceTimeSpanMs(Timer.GetElapsedTimeMs()),
+					 ProjectCount,
+					 ExpiredProjectCount);
 	   });
 	std::vector<Ref<Project>> ExpiredProjects;
 
@@ -1149,7 +1150,7 @@ ProjectStore::CollectGarbage(GcContext& GcCtx)
 
 	if (ExpiredProjects.empty())
 	{
-		ZEN_INFO("garbage collect SKIPPED, for '{}', no expired projects found", m_ProjectBasePath.string());
+		ZEN_DEBUG("garbage collect SKIPPED, for '{}', no expired projects found", m_ProjectBasePath.string());
 		return;
 	}
 
@@ -1167,20 +1168,20 @@ ProjectStore::CollectGarbage(GcContext& GcCtx)
 			RwLock::ExclusiveLockScope _(m_ProjectsLock);
 			if (!Project->IsExpired())
 			{
-				ZEN_INFO("ProjectStore::CollectGarbage skipped garbage collect of project '{}'. Project no longer expired.", ProjectId);
+				ZEN_DEBUG("ProjectStore::CollectGarbage skipped garbage collect of project '{}'. Project no longer expired.", ProjectId);
 				continue;
 			}
 			bool Success = Project->PrepareForDelete(PathToRemove);
 			if (!Success)
 			{
-				ZEN_INFO("ProjectStore::CollectGarbage skipped garbage collect of project '{}'. Project folder is locked.", ProjectId);
+				ZEN_DEBUG("ProjectStore::CollectGarbage skipped garbage collect of project '{}'. Project folder is locked.", ProjectId);
 				continue;
 			}
 			m_Projects.erase(Project->Identifier);
 			ProjectId = Project->Identifier;
 		}
 
-		ZEN_INFO("ProjectStore::CollectGarbage garbage collected project '{}'. Removing storage on disk", ProjectId);
+		ZEN_DEBUG("ProjectStore::CollectGarbage garbage collected project '{}'. Removing storage on disk", ProjectId);
 		if (PathToRemove.empty())
 		{
 			continue;
diff --git a/zenstore/blockstore.cpp b/zenstore/blockstore.cpp
index c8bf482fa..5d81d1120 100644
--- a/zenstore/blockstore.cpp
+++ b/zenstore/blockstore.cpp
@@ -168,7 +168,7 @@ BlockStore::Initialize(const std::filesystem::path&			  BlocksBasePath,
 					{
 						// Log removing unreferenced block
 						// Clear out unused blocks
-						ZEN_INFO("removing unused block at '{}'", Path);
+						ZEN_DEBUG("removing unused block at '{}'", Path);
 						std::error_code Ec;
 						std::filesystem::remove(Path, Ec);
 						if (Ec)
@@ -334,7 +334,7 @@ BlockStore::ReclaimSpace(const ReclaimSnapshotState&			Snapshot,
 
 	Stopwatch  TotalTimer;
 	const auto _ = MakeGuard([&] {
-		ZEN_INFO(
+		ZEN_DEBUG(
 			"reclaim space for '{}' DONE after {}, write lock: {} ({}), read lock: {} ({}), collected {} bytes, deleted #{} and moved "
 			"#{} "
 			"of #{} "
@@ -424,12 +424,12 @@ BlockStore::ReclaimSpace(const ReclaimSnapshotState&			Snapshot,
 
 	if (DryRun)
 	{
-		ZEN_INFO("garbage collect for '{}' DISABLED, found #{} {} chunks of total #{} {}",
-				 m_BlocksBasePath,
-				 DeleteCount,
-				 NiceBytes(OldTotalSize - NewTotalSize),
-				 TotalChunkCount,
-				 OldTotalSize);
+		ZEN_DEBUG("garbage collect for '{}' DISABLED, found #{} {} chunks of total #{} {}",
+				  m_BlocksBasePath,
+				  DeleteCount,
+				  NiceBytes(OldTotalSize - NewTotalSize),
+				  TotalChunkCount,
+				  OldTotalSize);
 		return;
 	}
 
diff --git a/zenstore/compactcas.cpp b/zenstore/compactcas.cpp
index d0c2f59ac..e52f5b7cb 100644
--- a/zenstore/compactcas.cpp
+++ b/zenstore/compactcas.cpp
@@ -386,7 +386,7 @@ CasContainerStrategy::CollectGarbage(GcContext& GcCtx)
 	// do a blocking operation and update the m_LocationMap after each new block is
 	// written and figuring out the path to the next new block.
 
-	ZEN_INFO("collecting garbage from '{}'", m_RootDirectory / m_ContainerBaseName);
+	ZEN_DEBUG("collecting garbage from '{}'", m_RootDirectory / m_ContainerBaseName);
 
 	uint64_t WriteBlockTimeUs		 = 0;
 	uint64_t WriteBlockLongestTimeUs = 0;
diff --git a/zenstore/filecas.cpp b/zenstore/filecas.cpp
index 1b53c405b..1d3542f62 100644
--- a/zenstore/filecas.cpp
+++ b/zenstore/filecas.cpp
@@ -847,7 +847,7 @@ FileCasStrategy::CollectGarbage(GcContext& GcCtx)
 {
 	ZEN_ASSERT(m_IsInitialized);
 
-	ZEN_INFO("collecting garbage from {}", m_RootDirectory);
+	ZEN_DEBUG("collecting garbage from {}", m_RootDirectory);
 
 	std::vector<IoHash>	  ChunksToDelete;
 	std::atomic<uint64_t> ChunksToDeleteBytes{0};
@@ -861,13 +861,13 @@ FileCasStrategy::CollectGarbage(GcContext& GcCtx)
 
 	Stopwatch  TotalTimer;
 	const auto _ = MakeGuard([&] {
-		ZEN_INFO("garbage collect for '{}' DONE after {}, deleted {} out of {} files, removed {} out of {}",
-				 m_RootDirectory,
-				 NiceTimeSpanMs(TotalTimer.GetElapsedTimeMs()),
-				 DeletedCount,
-				 ChunkCount,
-				 NiceBytes(OldTotalSize - m_TotalSize.load(std::memory_order::relaxed)),
-				 NiceBytes(OldTotalSize));
+		ZEN_DEBUG("garbage collect for '{}' DONE after {}, deleted {} out of {} files, removed {} out of {}",
+				  m_RootDirectory,
+				  NiceTimeSpanMs(TotalTimer.GetElapsedTimeMs()),
+				  DeletedCount,
+				  ChunkCount,
+				  NiceBytes(OldTotalSize - m_TotalSize.load(std::memory_order::relaxed)),
+				  NiceBytes(OldTotalSize));
 	});
 
 	IterateChunks([&](const IoHash& Hash, BasicFile& Payload) {
@@ -900,15 +900,15 @@ FileCasStrategy::CollectGarbage(GcContext& GcCtx)
 
 	if (ChunksToDelete.empty())
 	{
-		ZEN_INFO("gc for '{}' SKIPPED, nothing to delete", m_RootDirectory);
+		ZEN_DEBUG("gc for '{}' SKIPPED, nothing to delete", m_RootDirectory);
 		return;
 	}
 
-	ZEN_INFO("deleting file CAS garbage for '{}': {} out of {} chunks ({})",
-			 m_RootDirectory,
-			 ChunksToDelete.size(),
-			 ChunkCount.load(),
-			 NiceBytes(ChunksToDeleteBytes));
+	ZEN_DEBUG("deleting file CAS garbage for '{}': {} out of {} chunks ({})",
+			  m_RootDirectory,
+			  ChunksToDelete.size(),
+			  ChunkCount.load(),
+			  NiceBytes(ChunksToDeleteBytes));
 
 	if (GcCtx.IsDeletionMode() == false)
 	{