Duration between RequestNotPermitted

127 views Asked by At

I play with resilence4j so I've implemented following service:

@Service
@Slf4j
public class MyService {
    @CircuitBreaker(name = "myCircuitBreaker", fallbackMethod = "doSmthFallbackCb")
    @Retry(name = "doSmth", fallbackMethod = "doSmthFallback")
    @RateLimiter(name = "myRateLimiter")
    public String doSmth(String arg) {
        log.error("doSmth is called with argument = {}", arg);
        if (true) {
            throw new RuntimeException("Some exception");
        }
        return "Foo";
    }

    public String doSmthFallback(String arg, Exception e) {
        log.error("doSmthFallback retry with argument {} is called with exception {}, {}", arg, e.getMessage(), e.getClass());
        return "FallbackRetry";
    }

    public String doSmthFallbackCb(String arg, Exception e) {
        log.error("doSmthFallback circuit breaker with argument {} is called with exception {}, {}", arg, e.getMessage(), e.getClass());
        return "FallbackCircuitBreaker";
    }
}

and my config is:

resilience4j:
  retry:
    metrics:
      enabled: true
    retry-aspect-order: 2
    instances:
      doSmth:
        max-attempts: 3
        wait-duration: 10s
      sendEmail:
        max-attempts: 3
        wait-duration: 10s
  circuitbreaker:
    metrics:
      enabled: true
    circuit-breaker-aspect-order: 1
    instances:
      myCircuitBreaker:
        wait-duration-in-open-state: 1m
        permitted-number-of-calls-in-half-open-state: 3
        sliding-window-type: count-based
        sliding-window-size: 10
        minimum-number-of-calls: 20
        slow-call-duration-threshold: 10s
        slow-call-rate-threshold: 60
        failure-rate-threshold: 60
  ratelimiter:
    metrics:
      enabled: true
    rate-limiter-aspect-order: 3
    instances:
      myRateLimiter:
        register-health-indicator: true
        limit-for-period: 5
        limit-refresh-period: 120s
        timeout-duration: 0s
        allow-health-indicator-to-fail: true
        subscribe-for-events: true
        event-consumer-buffer-size: 50

my main method content:

for (int i = 0; i < 1000; i++) {
    myService.doSmth("" + i);
    Thread.sleep(5000);
}

I receive such a log:

2023-04-17 19:08:30.805 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 0
2023-04-17 19:08:40.822 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 0
2023-04-17 19:08:50.829 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 0
2023-04-17 19:08:50.830 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 0 is called with exception Some exception, class java.lang.RuntimeException
2023-04-17 19:08:55.841 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 1
2023-04-17 19:09:05.854 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 1
2023-04-17 19:09:15.868 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 1 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:09:40.885 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 2 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:10:05.919 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 3 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:10:30.935 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 4
2023-04-17 19:10:30.935 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 4 is called with exception Some exception, class java.lang.RuntimeException
2023-04-17 19:10:35.937 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 5
2023-04-17 19:10:45.952 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 5
2023-04-17 19:10:55.964 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 5
2023-04-17 19:10:55.964 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 5 is called with exception Some exception, class java.lang.RuntimeException
2023-04-17 19:11:00.975 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmth is called with argument = 6
2023-04-17 19:11:20.982 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 6 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:11:46.021 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 7 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:12:11.043 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 8 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
....

please notice following:

2023-04-17 19:09:15.868 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 1 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:09:40.885 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 2 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:10:05.919 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 3 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
...
2023-04-17 19:11:20.982 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 6 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:11:46.021 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 7 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
2023-04-17 19:12:11.043 ERROR 22256 --- [           main] r.v.u.e.s.MyService                      : doSmthFallback retry with argument 8 is called with exception RateLimiter 'myRateLimiter' does not permit further calls, class io.github.resilience4j.ratelimiter.RequestNotPermitted
...

Could you explain why there are 25 seconds delay between RequestNotPermitted ?

0

There are 0 answers