Published on

서킷 브레이커를 동작하게 하는 방법

Authors
  • avatar
    Name
    손예지(Liv)

MSA에서 사용되는 서킷브레이커에 대해서 학습을 하던중 서킷 브레이커가 예상한데로 동작하지 않는 부분을 발견했습니다.

오류 내용

사실, 서킷 브레이커는 직접 눈으로는 볼 수 없습니다. 서킷 브레이커의 상태 변화를 눈으로 확인하기 위해서는 프로메테우스와 그라파나 같은 도구를 활용해 시각적으로 볼 수 있습니다. 혹은 이벤트 리스너를 사용해 발생하는 시점을 로그로 확인했습니다. 저는 이벤트 리스너로 서킷 브레이커의 동작을 확인해 보려고 했습니다.

제가 생각했던 Fallback이 동작하는 시나리오는 아래와 같습니다.

  1. 상품을 호출하는 URI 인 product API 를 호출했을때 Fallback 이 발생한다.
  2. Fallback 이 발생한 후 일정 시간 이후에 product/111 을 제외한 올바른 URI를 호출하면 다시 정상적인 product API가 호출된다.

예상결과는 Fallback이 발생한 이후 일정시간의 break가 있고, 이후에 다시 동작하는 것이었습니다. 그런데 어플리케이션 실행시 아래 로그 처럼 Fallback은 주지만 productId 1111을 호출했을 때 멈춤없이 바로 실행이 되는것을 발견했습니다.

2024-11-22T15:43:05.647+09:00  WARN 1176 --- [sample] [io-19090-exec-4] c.s.c.r.sample.ProductService            : ###Received empty body for productId: 111
2024-11-22T15:43:05.649+09:00  INFO 1176 --- [sample] [io-19090-exec-4] c.s.c.r.sample.ProductService            : #######CircuitBreaker Error: 2024-11-22T15:43:05.649608+09:00[Asia/Seoul]: CircuitBreaker 'productService' recorded an error: 'java.lang.RuntimeException: Empty response body'. Elapsed time: 2 ms
2024-11-22T15:43:05.656+09:00 ERROR 1176 --- [sample] [io-19090-exec-4] c.s.c.r.sample.ProductService            : ####Fallback triggered for productId: 111 due to: Empty response body
2024-11-22T15:43:11.763+09:00  INFO 1176 --- [sample] [io-19090-exec-6] c.s.c.r.sample.ProductService            : ###Fetching product details for productId: 111

해결 방법

application.yml 파일에서 slidingWindow 관련 설정을 살펴보다 호출 횟수에 대한 설정이 있는 것을 발견하게 되었습니다. slidingWindowType 설정은 COUNT_BASED 로 설정했기 때문에 호출 횟수를 기반으로 동작합니다. 동작하는 순서는 아래와 같습니다.

resilience4j:
  circuitbreaker:
    configs:
      default:  
        registerHealthIndicator: true  
        slidingWindowType: COUNT_BASED  
        slidingWindowSize: 5  
        minimumNumberOfCalls: 5  
        slowCallRateThreshold: 100  
        slowCallDurationThreshold: 60000  
        failureRateThreshold: 50  
        permittedNumberOfCallsInHalfOpenState: 3  
        waitDurationInOpenState: 20s
  1. slidingWindowSize: 5 와 minimumNumberOfCalls: 5 설정을 통해 5번의 호출을 감지합니다.
  2. failureRateThreshold: 50 설정을 통해 실패율 50% 가 넘으면 Open 되도록 합니다. 5번의 시도의 50 % 는 3번의 실패를 해야한다고 볼 수 있습니다.
  3. 서킷이 Open 되면 waitDurationInOpenState: 20s 에 의해 20초 동안 모든 호출이 차단됩니다.
  4. 20초가 지나면 permittedNumberOfCallsInHalfOpenState: 3 은 3번의 호출을 허용합니다.
  5. 여기서 3번 성공적으로 호출이 되면 서킷은 Closed 상태가 되고 실패하면 Open 상태가 되어 다시 20초동안 차단됩니다.

아래 이벤트 로그를 통해 실행 순서를 확인할 수 있습니다. CircuitBreaker Failure Rate Exceeded 로그가 노출되는 시점 이후로 호출이 차단되는 것을 볼 수 있습니다.

2024-11-22T15:58:39.823+09:00 ERROR 1556 --- [sample] [io-19090-exec-2] c.s.c.r.sample.ProductService            : ####Fallback triggered for productId: 111 due to: Empty response body
2024-11-22T15:58:45.049+09:00  INFO 1556 --- [sample] [io-19090-exec-5] c.s.c.r.sample.ProductService            : ###Fetching product details for productId: 111
2024-11-22T15:58:45.054+09:00  WARN 1556 --- [sample] [io-19090-exec-5] c.s.c.r.sample.ProductService            : ###Received empty body for productId: 111
2024-11-22T15:58:45.057+09:00  INFO 1556 --- [sample] [io-19090-exec-5] c.s.c.r.sample.ProductService            : #######CircuitBreaker Error: 2024-11-22T15:58:45.056051+09:00[Asia/Seoul]: CircuitBreaker 'productService' recorded an error: 'java.lang.RuntimeException: Empty response body'. Elapsed time: 6 ms
2024-11-22T15:58:45.058+09:00 ERROR 1556 --- [sample] [io-19090-exec-5] c.s.c.r.sample.ProductService            : ####Fallback triggered for productId: 111 due to: Empty response body
2024-11-22T15:58:48.842+09:00  INFO 1556 --- [sample] [io-19090-exec-8] c.s.c.r.sample.ProductService            : ###Fetching product details for productId: 1111
2024-11-22T15:58:52.343+09:00  INFO 1556 --- [sample] [io-19090-exec-1] c.s.c.r.sample.ProductService            : ###Fetching product details for productId: 111
2024-11-22T15:58:52.344+09:00  WARN 1556 --- [sample] [io-19090-exec-1] c.s.c.r.sample.ProductService            : ###Received empty body for productId: 111
2024-11-22T15:58:52.345+09:00  INFO 1556 --- [sample] [io-19090-exec-1] c.s.c.r.sample.ProductService            : #######CircuitBreaker Error: 2024-11-22T15:58:52.345078+09:00[Asia/Seoul]: CircuitBreaker 'productService' recorded an error: 'java.lang.RuntimeException: Empty response body'. Elapsed time: 1 ms
2024-11-22T15:58:52.347+09:00  INFO 1556 --- [sample] [io-19090-exec-1] c.s.c.r.sample.ProductService            : #######CircuitBreaker Failure Rate Exceeded: 2024-11-22T15:58:52.347723+09:00[Asia/Seoul]: CircuitBreaker 'productService' exceeded failure rate threshold. Current failure rate: 60.0
2024-11-22T15:58:52.368+09:00  INFO 1556 --- [sample] [io-19090-exec-1] c.s.c.r.sample.ProductService            : #######CircuitBreaker State Transition: 2024-11-22T15:58:52.367995+09:00[Asia/Seoul]: CircuitBreaker 'productService' changed state from CLOSED to OPEN
2024-11-22T15:58:52.368+09:00 ERROR 1556 --- [sample] [io-19090-exec-1] c.s.c.r.sample.ProductService            : ####Fallback triggered for productId: 111 due to: Empty response body
2024-11-22T15:58:54.813+09:00  INFO 1556 --- [sample] [io-19090-exec-2] c.s.c.r.sample.ProductService            : #######CircuitBreaker Call Not Permitted: 2024-11-22T15:58:54.812775+09:00[Asia/Seoul]: CircuitBreaker 'productService' recorded a call which was not permitted.
2024-11-22T15:58:54.814+09:00 ERROR 1556 --- [sample] [io-19090-exec-2] c.s.c.r.sample.ProductService            : ####Fallback triggered for productId: 111 due to: CircuitBreaker 'productService' is OPEN and does not permit further calls
2024-11-22T15:59:13.401+09:00  INFO 1556 --- [sample] [io-19090-exec-5] c.s.c.r.sample.ProductService            : #######CircuitBreaker State Transition: 2024-11-22T15:59:13.400929+09:00[Asia/Seoul]: CircuitBreaker 'productService' changed state from OPEN to HALF_OPEN
2024-11-22T15:59:13.404+09:00  INFO 1556 --- [sample] [io-19090-exec-5] c.s.c.r.sample.ProductService            : ###Fetching product details for productId: 1111
2024-11-22T15:59:17.756+09:00  INFO 1556 --- [sample] [io-19090-exec-7] c.s.c.r.sample.ProductService            : ###Fetching product details for productId: 11
2024-11-22T15:59:18.272+09:00  INFO 1556 --- [sample] [io-19090-exec-8] c.s.c.r.sample.ProductService            : ###Fetching product details for productId: 1
2024-11-22T15:59:18.278+09:00  INFO 1556 --- [sample] [io-19090-exec-8] c.s.c.r.sample.ProductService            : #######CircuitBreaker State Transition: 2024-11-22T15:59:18.278877+09:00[Asia/Seoul]: CircuitBreaker 'productService' changed state from HALF_OPEN to CLOSED

알게된점

slidingWindow 설정을 확인한 뒤 설정한 그대로 실행되고 있었다는 것을 알게되었습니다.그동안 application.yml 파일에서 설정하는 값들은 넣어야 하는 값들이지만 왜 넣어야 하는지는 잘 몰랐는데, 서킷 브레이크 실습을 하면서 하나의 값들이 어떤 영향을 주는지 명확하게 알 수 있었습니다. 코드에 오류가 있어서 로그를 못준다고 생각해서 계속 코드만 보고 있었는데, 설정 부분도 어플리케이션 동작에 큰 역할을 한다는 것을 다시 한번 느꼈습니다.

참고자료:
Getting started with resilience4j-circuitbreaker
내일배움캠프 MSA 강의 중 서킷 브레이커 부분 강의 참고
개발자 의식의 흐름대로 적용해보는 서킷브레이커

View on GitHub