From ca71a7ab2c0267b3b6b8b0e05924abfa594e2829 Mon Sep 17 00:00:00 2001 From: Martin Tournoij Date: Wed, 14 Aug 2024 15:28:53 +0100 Subject: [PATCH] Only log hearbeat if job count changed Right now it will log this every five seconds, which really clobbers my terminal/logs, mostly with fairly useless debug messages: 15:27 INFO producer: Heartbeat num_completed_jobs = 0 num_jobs_running = 0 queue = default 15:27 INFO producer: Heartbeat num_completed_jobs = 0 num_jobs_running = 0 queue = default 15:27 INFO producer: Heartbeat num_completed_jobs = 0 num_jobs_running = 0 queue = default 15:27 INFO producer: Heartbeat num_completed_jobs = 0 num_jobs_running = 0 queue = default I originally considered changing the InfoContext() to DebugContext(), but doing an Info log only if the status changed seemed like a good middle ground. --- producer.go | 19 ++++++++++++++----- 1 file changed, 14 insertions(+), 5 deletions(-) diff --git a/producer.go b/producer.go index 5b5f36cc..4a5a5b4a 100644 --- a/producer.go +++ b/producer.go @@ -535,16 +535,25 @@ func (p *producer) dispatchWork(workCtx context.Context, count int, fetchResultC func (p *producer) heartbeatLogLoop(ctx context.Context) { ticker := time.NewTicker(5 * time.Second) defer ticker.Stop() + type jobCount struct { + ran uint64 + active int + } + var prevCount jobCount for { select { case <-ctx.Done(): return case <-ticker.C: - p.Logger.InfoContext(ctx, p.Name+": Heartbeat", - slog.Uint64("num_completed_jobs", p.numJobsRan.Load()), - slog.Int("num_jobs_running", int(p.numJobsActive.Load())), - slog.String("queue", p.config.Queue), - ) + curCount := jobCount{ran: p.numJobsRan.Load(), active: int(p.numJobsActive.Load())} + if curCount != prevCount { + p.Logger.InfoContext(ctx, p.Name+": Producer job counts", + slog.Uint64("num_completed_jobs", curCount.ran), + slog.Int("num_jobs_running", curCount.active), + slog.String("queue", p.config.Queue), + ) + } + prevCount = curCount } } }