zap icon indicating copy to clipboard operation
zap copied to clipboard

Provide rate-limited async logging interface

Open Dentrax opened this issue 2 years ago • 4 comments

Is your feature request related to a problem? Please describe.

The initial idea was filed at issue #969. Let's carry this one to discuss further about.

I'm very interested and would be great to see ordered-and-async-rate-limited-logging implementation on zap itself.

The code snipped at aforementioned issue dropped by @midnightexigent is sync and blocking operation, which would be resulting in more slowed-down throttled runtime (IMO).

My use-case is: I do NOT want to do blocking logging since it drops overall runtime performance slightly. So async logging (proposed at #988) is very promising and exactly what I was looking for to combine with rate package. On the other hand, it'd be nice to have rate feature in both sync and async logging.

If you're about to ask: "Why you need rate-limiting, isn't it async already?". Imagine we're running a low-end device with limited memory size and dropping hundreds or thousands of logs per second. I just don't immediate brust into zap's in-memory logging buffer. There would also some open questions such as: "What if the buffer filled up and couldn't expand anymore? What would be the fallback options?", etc.

To sum up the overall idea, we should gracefully rate limit incoming logs into buffer by NOT creating any throttling due to the number of log pushes that buffer can handle in a certain period.

Describe the solution you'd like

Provide configurable rate-limited option for both of sync and async logging.

Describe alternatives you've considered -

Is this a breaking change? NO

Additional context

Example implementations:

/cc @abhinav @prashantv @midnightexigent @springionic

Dentrax avatar Feb 11 '23 12:02 Dentrax

Is there a plan to take this up? @abhinav @sywhang I would like to work on this

SoulPancake avatar May 28 '23 17:05 SoulPancake

Thanks for filing this, @Dentrax, and the ping @SoulPancake. The proposal sounds reasonable at a first glance, and the right implementation would likely be welcome.

I need a little clarification, though:

As I understand it, when we say "async logging" here, we want to avoid writing to the file in the same goroutine that called log.Info. That makes sense. The idea of limiting the rate at which we fill up the buffer also makes sense. But what are you thinking for the behavior there? Drop messages if the rate is too high for the buffer to accept? Or sample them?

And I agree that these two functionalities: async log writer and rate limiter should be separate and composible.

I'm aware that @prashantv has had success in the past with a more complex asynchronous logger than the buffered writer that Zap provides. I don't remember the details for how it behaved, though.

abhinav avatar Aug 19 '23 05:08 abhinav

@abhinav to add some other considerations to this. i think rate limiting is just one solution to the problem of having too much data for the buffer. Another option is FIFO into the void, or just dropping all new messages until there is space in the buffer. Seems there should be a config/param to allow specifying buffer overflow behavior.

Also, it seems you don't even need to reach a full buffer to demonstrate the need for async. Right now, if i place any message in a buffer, it seems to lock up I/O for the main thread on the next flush, if the writer is unable to write. To demonstrate, just pause output (ctrl+s) in a terminal receiving log output.

EDIT: upon further investigation, it seems this lockup is due to mutex contention, where Sync is holding the lock, and Write is waiting on it. I believe a separate goroutine would still save the main thread, but it's also probably best addressed by using TryLock w/ a timeout on the acquisition in Write and/or some sort of yield on Sync/Flush

rdugan avatar Sep 15 '23 08:09 rdugan

Thanks for filing this, @Dentrax, and the ping @SoulPancake. The proposal sounds reasonable at a first glance, and the right implementation would likely be welcome.

I need a little clarification, though:

As I understand it, when we say "async logging" here, we want to avoid writing to the file in the same goroutine that called log.Info. That makes sense. The idea of limiting the rate at which we fill up the buffer also makes sense. But what are you thinking for the behavior there? Drop messages if the rate is too high for the buffer to accept? Or sample them?

And I agree that these two functionalities: async log writer and rate limiter should be separate and composible.

I'm aware that @prashantv has had success in the past with a more complex asynchronous logger than the buffered writer that Zap provides. I don't remember the details for how it behaved, though.

Better not to sample or drop when full. latest log are almost always more important, especially when log about state transition. image a burst of state transistion(log) and saddenly stop, you wont like to miss latest state log at that moment. I'd say replace is better, when buffer full replace with new log or, when rate limit reach, buffer new log might works

LeGamerDc avatar Jul 31 '24 03:07 LeGamerDc