Rate limiter is off for first invokations

[mpsota]

Firstly, thanks for your time spend on this lib. Unfortunately I can see issue when using fn-throttler which is a blocker for me.

I'm trying to use API with contraint 1 request per 1500ms. To make things easier here, lets assume I want to make 1 call not more often than every 2 seconds. Code:

(def api-throttler (throttler/fn-throttler 1/2 :second))
(def test-fn (api-throttler
               (fn [x]
                    (log/debug "Processed:" x))))
;; and a test
(dotimes [i 10]
  (test-fn i))

Result:

2021-07-29T21:12:10.782Z DEBUG [] - Processed: 0
2021-07-29T21:12:10.785Z DEBUG [] - Processed: 1
2021-07-29T21:12:12.780Z DEBUG [] - Processed: 2
2021-07-29T21:12:14.780Z DEBUG [] - Processed: 3
2021-07-29T21:12:16.781Z DEBUG [] - Processed: 4
2021-07-29T21:12:18.781Z DEBUG [] - Processed: 5
2021-07-29T21:12:20.782Z DEBUG [] - Processed: 6
2021-07-29T21:12:22.783Z DEBUG [] - Processed: 7
2021-07-29T21:12:24.784Z DEBUG [] - Processed: 8
2021-07-29T21:12:26.785Z DEBUG [] - Processed: 9

Please notice that first and second calls are done withing 0.003sec :( API is not happy.

When using pmap the issue is even greater:

(pmap test-fn (range 10))

2021-07-29T21:14:21.642Z DEBUG [] - Processed: 4
2021-07-29T21:14:21.642Z DEBUG [] - Processed: 2
2021-07-29T21:14:22.810Z DEBUG [] - Processed: 3
2021-07-29T21:14:24.811Z DEBUG [] - Processed: 8
2021-07-29T21:14:26.810Z DEBUG [] - Processed: 6
2021-07-29T21:14:28.811Z DEBUG [] - Processed: 0
2021-07-29T21:14:30.810Z DEBUG [] - Processed: 1
2021-07-29T21:14:32.811Z DEBUG [] - Processed: 5
2021-07-29T21:14:34.812Z DEBUG [] - Processed: 7
2021-07-29T21:14:36.811Z DEBUG [] - Processed: 9

4->2 - no delay 8->6 - 0.001 too early 0->1 - 0.001 too early 7->9 - 0.001 too early again :(

Am I missing something?

[liath]

Seems like this is caused by pipe taking a token and waiting at https://github.com/brunoV/throttler/blob/master/src/throttler/core.clj#L53 while bucket filler thread is still adding tokens. So if there's any kind of delay between the throttled function being created and its first invocation you have a kind of double spend as the first call was already paid for and the next call will have a token waiting so also gets run almost immediately.

[liath]

Here's the same test but the throttled fn is used immediately:

$ lein repl
OpenJDK 64-Bit Server VM warning: Options -Xverify:none and -noverify were deprecated in JDK 13 and will likely be removed in a future release.
nREPL server started on port 41025 on host 127.0.0.1 - nrepl://127.0.0.1:41025
REPL-y 0.4.4, nREPL 0.8.3
Clojure 1.10.0
OpenJDK 64-Bit Server VM 14.0.2+12-Ubuntu-120.04
    Docs: (doc function-name-here)
          (find-doc "part-of-name-here")
  Source: (source function-name-here)
 Javadoc: (javadoc java-object-or-class-here)
    Exit: Control+D or (exit) or (quit)
 Results: Stored in vars *1, *2, *3, an exception in *e

user=> (require '[clojure.tools.logging :as log]) (require '[throttler.core :as throttler]) (def api-throttler (throttler/fn-throttler 1/2 :second)) (def test-fn (api-throttler (fn [x] (log/error "Processed:" x)))) (dotimes [i 10] (test-fn i))
nil
nil
#'user/api-throttler
#'user/test-fn
Aug 12, 2021 11:19:31 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 0
Aug 12, 2021 11:19:33 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 1
Aug 12, 2021 11:19:35 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 2
Aug 12, 2021 11:19:37 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 3
Aug 12, 2021 11:19:39 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 4
Aug 12, 2021 11:19:41 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 5
Aug 12, 2021 11:19:43 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 6
Aug 12, 2021 11:19:45 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 7
Aug 12, 2021 11:19:47 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 8
Aug 12, 2021 11:19:49 AM clojure.tools.logging$eval2285$fn__2288 invoke
SEVERE: Processed: 9
nil
user=>

[aiba]

I'm also seeing this behavior with the first few invocations. As with @mpsota , this is a blocker for me for this library.