fix gc logging (#213)

* Don't output time to next GC if time is "infinite".
* Do immediate check of GC status on thread startup instead of waiting montior intervall first.
* set up reasonable gc defaults
* changelog

3 files changed, 43 insertions, 30 deletions

diff --git a/CHANGELOG.md b/CHANGELOG.md
index bfce09d7b..2211b8404 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -5,15 +5,19 @@
  - `/z$/{namespace}/{bucket}` - get bucket info
 - Feature: Added project store oplog info: `markerpath`,  `totalsize`, `opcount`, `expired` on GET requests for oplog
 - Feature: Added project store project info: `expired` on GET requests for project
-- Feature: Added project store root route `/prj` which is identical to `/prj/list`
+- Feature :Added project store root route `/prj` which is identical to `/prj/list`
 - Feature: zen command line tool `cache-info` to show cache, namespace or bucket info
 - Feature: zen command line tool `project-info` to show store, project or oplog info
 - Feature: zen command line tool `project-drop` to drop project or oplog
 - Feature: zen command line tool `gc` to trigger a GC run
 - Feature: zen command line tool `gc-info` to check status of GC
+- Bugfix: Don't log "time to next GC" if time to next GC is not set
+- Improvement: Don't wait for GC monitor interval before doing first GC check
 - Improvement: zen command line tool now fails on any unrecognized arguments
 - Improvement: zen command line tool now displays extra help for all sub-commands
 - Improvement: host address can now be configured for zen command line tool `drop` command
+- Changed: Default GC interval set to 1 hour
+- Changed: Default GC cache duration set to 2 weeks
 
 ## 0.2.1
 - Feature: Oplog level GC in project store. If gc marker file path is given by UE, oplogs will be GC:d when marker file is deleted (and GC is triggered)
diff --git a/zenserver/config.cpp b/zenserver/config.cpp
index 057b26c5b..d7233a6f4 100644
--- a/zenserver/config.cpp
+++ b/zenserver/config.cpp
@@ -462,35 +462,35 @@ ParseCliOptions(int argc, char* argv[], ZenServerOptions& ServerOptions)
 	options.add_option("gc",
 					   "",
 					   "gc-small-objects",
-					   "Whether garbage collection is enabled or not.",
+					   "Whether garbage collection of small objects is enabled or not.",
 					   cxxopts::value<bool>(ServerOptions.GcConfig.CollectSmallObjects)->default_value("true"),
 					   "");
 
 	options.add_option("gc",
 					   "",
 					   "gc-interval-seconds",
-					   "Garbage collection interval in seconds. Default set to 0 (Off).",
-					   cxxopts::value<int32_t>(ServerOptions.GcConfig.IntervalSeconds)->default_value("0"),
+					   "Garbage collection interval in seconds. Default set to 3600 (1 hour).",
+					   cxxopts::value<int32_t>(ServerOptions.GcConfig.IntervalSeconds)->default_value("3600"),
 					   "");
 
 	options.add_option("gc",
 					   "",
 					   "gc-cache-duration-seconds",
-					   "Max duration in seconds before Z$ entries get evicted.",
-					   cxxopts::value<int32_t>(ServerOptions.GcConfig.Cache.MaxDurationSeconds)->default_value("86400"),
+					   "Max duration in seconds before Z$ entries get evicted. Default set to 1209600 (2 weeks)",
+					   cxxopts::value<int32_t>(ServerOptions.GcConfig.Cache.MaxDurationSeconds)->default_value("1209600"),
 					   "");
 
 	options.add_option("gc",
 					   "",
 					   "disk-reserve-size",
-					   "Size of gc disk reserve in bytes.",
+					   "Size of gc disk reserve in bytes. Default set to 268435456 (256 Mb).",
 					   cxxopts::value<uint64_t>(ServerOptions.GcConfig.DiskReserveSize)->default_value("268435456"),
 					   "");
 
 	options.add_option("gc",
 					   "",
 					   "gc-monitor-interval-seconds",
-					   "Garbage collection monitoring interval in seconds.",
+					   "Garbage collection monitoring interval in seconds. Default set to 30 (30 seconds)",
 					   cxxopts::value<int32_t>(ServerOptions.GcConfig.MonitorIntervalSeconds)->default_value("30"),
 					   "");
 
diff --git a/zenstore/gc.cpp b/zenstore/gc.cpp
index cb155dad1..8d3b8d018 100644
--- a/zenstore/gc.cpp
+++ b/zenstore/gc.cpp
@@ -666,7 +666,7 @@ GcScheduler::Trigger(const GcScheduler::TriggerParams& Params)
 void
 GcScheduler::SchedulerThread()
 {
-	std::chrono::seconds WaitTime = m_Config.MonitorInterval;
+	std::chrono::seconds WaitTime{0};
 
 	for (;;)
 	{
@@ -682,7 +682,13 @@ GcScheduler::SchedulerThread()
 			break;
 		}
 
-		if (!m_Config.Enabled || (!Timeout && Status() == GcSchedulerStatus::kIdle))
+		if (!m_Config.Enabled)
+		{
+			WaitTime = std::chrono::seconds::max();
+			continue;
+		}
+
+		if (!Timeout && Status() == GcSchedulerStatus::kIdle)
 		{
 			continue;
 		}
@@ -721,8 +727,6 @@ GcScheduler::SchedulerThread()
 				ZEN_WARN("get disk space info FAILED, reason: '{}'", Ec.message());
 			}
 
-			std::chrono::seconds RemaingTime = std::chrono::duration_cast<std::chrono::seconds>(m_NextGcTime - GcClock::Now());
-
 			const int64_t				PressureGraphLength = 30;
 			const std::chrono::duration LoadGraphTime		= PressureGraphLength * m_Config.MonitorInterval;
 			std::vector<uint64_t>		DiskDeltas;
@@ -741,11 +745,6 @@ GcScheduler::SchedulerThread()
 															  MaxLoad);
 			}
 
-			if (RemaingTime < std::chrono::seconds::zero())
-			{
-				RemaingTime = std::chrono::seconds::zero();
-			}
-
 			std::string LoadGraph;
 			LoadGraph.resize(DiskDeltas.size(), '0');
 			if (DiskDeltas.size() > 0 && MaxLoad > 0)
@@ -772,20 +771,30 @@ GcScheduler::SchedulerThread()
 			}
 
 			bool DiskSpaceGCTriggered = GcDiskSpaceGoal > 0;
+
+			std::chrono::seconds RemaingTime = std::chrono::duration_cast<std::chrono::seconds>(m_NextGcTime - GcClock::Now());
+
+			if (RemaingTime < std::chrono::seconds::zero())
+			{
+				RemaingTime = std::chrono::seconds::zero();
+			}
+
 			bool TimeBasedGCTriggered = !DiskSpaceGCTriggered && RemaingTime.count() == 0;
-			ZEN_INFO("{} in use,{} {} of total {} free disk space, disk writes last {} per {} [{}], peak {}/s. {}",
-					 NiceBytes(TotalSize.DiskSize),
-					 DiskSizeSoftLimit == 0 ? "" : fmt::format(" {} soft limit,", NiceBytes(DiskSizeSoftLimit)),
-					 NiceBytes(Space.Free),
-					 NiceBytes(Space.Total),
-					 NiceTimeSpanMs(uint64_t(std::chrono::milliseconds(LoadGraphTime).count())),
-					 NiceTimeSpanMs(uint64_t(std::chrono::milliseconds(LoadGraphTime).count() / PressureGraphLength)),
-					 LoadGraph,
-					 NiceBytes(MaxLoad * uint64_t(std::chrono::seconds(1).count()) / uint64_t(std::chrono::seconds(LoadGraphTime).count())),
-					 DiskSpaceGCTriggered ? fmt::format("Disk use threshold triggered, trying to reclaim {}. ", NiceBytes(GcDiskSpaceGoal))
-					 : TimeBasedGCTriggered ? "GC schedule triggered."
-											: fmt::format("{} until next scheduled GC.",
-														  NiceTimeSpanMs(uint64_t(std::chrono::milliseconds(RemaingTime).count()))));
+			ZEN_INFO(
+				"{} in use,{} {} of total {} free disk space, disk writes last {} per {} [{}], peak {}/s. {}",
+				NiceBytes(TotalSize.DiskSize),
+				DiskSizeSoftLimit == 0 ? "" : fmt::format(" {} soft limit,", NiceBytes(DiskSizeSoftLimit)),
+				NiceBytes(Space.Free),
+				NiceBytes(Space.Total),
+				NiceTimeSpanMs(uint64_t(std::chrono::milliseconds(LoadGraphTime).count())),
+				NiceTimeSpanMs(uint64_t(std::chrono::milliseconds(LoadGraphTime).count() / PressureGraphLength)),
+				LoadGraph,
+				NiceBytes(MaxLoad * uint64_t(std::chrono::seconds(1).count()) / uint64_t(std::chrono::seconds(LoadGraphTime).count())),
+				DiskSpaceGCTriggered   ? fmt::format("Disk use threshold triggered, trying to reclaim {}. ", NiceBytes(GcDiskSpaceGoal))
+				: TimeBasedGCTriggered ? "GC schedule triggered."
+				: m_NextGcTime == GcClock::TimePoint::max()
+					? ""
+					: fmt::format("{} until next scheduled GC.", NiceTimeSpanMs(uint64_t(std::chrono::milliseconds(RemaingTime).count()))));
 
 			if (!DiskSpaceGCTriggered && !TimeBasedGCTriggered)
 			{