riverqueue / river

Fast and reliable background jobs in Go
https://riverqueue.com
Mozilla Public License 2.0
3.51k stars 94 forks source link

Only log hearbeat if status changed #529

Closed arp242 closed 2 months ago

arp242 commented 2 months ago

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.

ccoVeille commented 2 months ago

I like your changes, but I would like to suggest something.

The heartbeat could be logged on each call with debug level, and the state change is logged with info level.

It would help a lot when a debug is needed.

I'm a bit afraid no log at all could lead to problem

arp242 commented 2 months ago

I'm a bit afraid no log at all could lead to problem

@ccoVeille I don't think this will actually log less information? It just won't log if the message will be identical (because none of the log parameters changed).

ccoVeille commented 2 months ago

heartbeat will be silent if nothing changed.

That's what your PR is about.

But won't it log nothing for hours if nothing changed. Or maybe I missed something in the conditions.

What will affect the count?

brandur commented 2 months ago

@ccoVeille So I think the idea is that while yes, nothing gets logged if nothing is changing, this might be a reasonable compromise for most systems. i.e. Any systems were any jobs are moving through queues at all, you'll see logging basically the same as you did before. But for systems where nothing is happening (like in say dev), we bias towards quieter log outputs.

This seems to make sense to me, although I can imagine an alternative where we should make it a Debug line and the client gets even quieter, and those who want a higher output client can either use debug level, or attach their own hooks into the even system.

Thoughts?

brandur commented 2 months ago

Thanks!

ccoVeille commented 2 months ago

I'm fine and agree with what you said.

I might open a PR with what I was thinking about. But my initial comment was a suggestion while the changes involved in the PR were already great.

So no worries