Rate limiting ignored

[deepxg]

I have an appender that sends stuff to Slack, and I had hoped that I'd rate limited it properly, but it occasionally goes bonkers. Is there any obvious issue with this config?

.
.
.
:appenders {
                    :slack
                    {:enabled? true
                     :async? false
                     :min-level :warn
                     :rate-limit [[1 1000]]
                     :output-fn :inherit}
.
.
.

I'd assumed that meant it'd send no more than 1 message a second, but that's not the case.

[ptaoussanis]

Hi there :-)

Your config looks okay in principle.

Could you please provide some context? E.g. what you mean by "goes bonkers", if this only happens with Slack, if you have any reproducible example, etc.

[deepxg]

I think my issue here was I was expecting rate limiting to occur at the appender level (i.e. stop flooding our Slack channel), but instead it's at the error source level. So it was working, just wasn't really doing what I expected.

[boechat107]

@deepxg, I think I had the same doubt about the rate limit configuration. After reading the source code and executing some tests, I concluded the rate limit is message-dependent.

We need to think of the rate limit for each possible logging message. If all logging messages are different, no rate limit kicks in.

Is my observation correct, @ptaoussanis?

[boechat107]

The first time I tried to test the rate limit my logging messages had the value of a counter, and no limit was ever imposed. I saw the limits kicking in when I logged only two different messages in a loop.

[ptaoussanis]

Hi there! Timbre uses this heuristic for identifying logging calls for the purposes of rate-limiting, etc.

I.e. each unique combination of the following identifies an individual rate-limiter:

1. Each individual Timbre macro form (i.e. callsite, e.g. (timbre/infof ...)).
2. When applicable, the particular message format string (only applicable for format-style logging, otherwise nil).
3. An optional manually-provided hash argument (an advanced + currently undocumented feature) [see R1] or (common-case) the combination of all other arguments provided to the logging call.

I.e. you can think of the default limiter behaviour as per (logging callsite and argument content). I.e. the main purpose of the default behaviour is to prevent the exact same repeated logical event from logging over and over.

If you'd prefer alternative behaviour, you can either:

• Provide the optional manual hash argument in (3) above [see R1].
• Or use your own rate limiter - manually or via middleware. Timbre just uses taoensso.encore/limiter under-the-covers. This is a high performance and very flexible general-use rate limiter.

Hope that helps! Cheers :-)

[R1] e.g. (timbre/infof ^:meta {:hash "my-logging-hash"} "User %s logged in" user-name).

[boechat107]

Thanks for the quick response, @ptaoussanis!

My tests confirm everything you said. I was able to find the hash composition here after your comment.

Wouldn't be worth it to add a link to your comment in *config* docstring?

[ptaoussanis]

Will add some documentation on the next release 👍

[ptaoussanis]

Rate limiting behaviour will be explained in more detail in forthcoming release, thanks Andre!