이벤트 루프 스레드(Event-Loop thread), 워커 스레드(Worker thread) 관련 Property에 따른 성능 밴드 튜닝

참고 문서

• Eclipse: Vertx.io Documentation

이 문서의 내용

테스트 환경 및 주요 아젠다

Vertx는 Node.js와 같은 Reactor 패턴 기반의 프레임워크입니다.

전통적인 Reactor 패턴에서는 이벤트 루프(Event-loop)라고 불리우는 단일 스레드가 이벤트를 핸들러에 전달합니다.

반면 Vertx는 Multi-Reactor 패턴으로써 여러 개의 이벤트 루프 스레드가 이벤트를 처리합니다.

이 프로젝트는 이벤트 루프 스레드와 워커 스레드(Worker thread)에 병목을 발생시키며 성능 밴드(Bandwith)를 확장하는 것을 목표로 합니다.

워커 스레드는 워크로드가 긴 작업을 수행하기 위해서 이벤트 루프 스레드와 별개로 동작하는 스레드입니다.

테스트를 위해서 스레드에서 차단(Blocking) 코드를 실행하며, 이를 일종의 트래픽이라고 가정합니다.

이 프로젝트의 개발 환경

• 프로젝트 구현
  • Open JDK 12.0.1
  • Gradle : vertx-core 3.7.1
  • Gradle : vertx-micrometer-metrics 3.7.1
  • Gradle : micrometer-registry-prometheus 1.10.5
• 성능 측정을 위한 대시보드 구현
  • Prometheus in docker(image:prom/prometheus)
  • Grafana in docker(grafana/grafana)

이벤트 루프 스레드 차단

Reactor 패턴에서 이벤트 루프 스레드는 절대로 차단해서는 안되는 황금률입니다.

이벤트 루프 스레드가 차단되면 Vertx 애플리케이션에서는 다음과 같은 경고 로그를 표시합니다.

경고 로그는 차단이 해제될 때까지 반복 표시되며 io.vertx.core.VertxOptions에서 표시 방식을 수정 할 수 있습니다.

[WARNING]Thread Thread[vert.x-eventloop-thread-0,5,main] has been blocked for 3808 ms, time limit is 3000 ms 
[WARNING]Thread Thread[vert.x-eventloop-thread-0,5,main] has been blocked for 4813 ms, time limit is 3000 ms 
[WARNING]Thread Thread[vert.x-eventloop-thread-0,5,main] has been blocked for 5818 ms, time limit is 3000 ms 
io.vertx.core.VertxException: Thread blocked
    ...

표시되는 로그에서 vert.x-eventloop-thread-0,5,main은 차단된 스레드 풀 이름입니다.

여기서는 이벤트 루프 스레드(vert.x-eventloop-thread)가 차단되었으며, 스레드 풀 내에서의 ID는 0번입니다(vert.x-eventloop-thread-0).

has been blocked for 3808 ms, time limit is 3000 ms는 3808 ms동안 해당 스레드가 차단된 상태를 나타냅니다.

차단에 대한 경고 로그는 3000ms로 기록됩니다.

이벤트 루프 스레드의 차단 경고 로그와 관련된 프로퍼티를 통해 표시 방식을 변경 할 수 있습니다. 

경고 로그는 차단이 해제될 때까지 반복 표시되며 io.vertx.core.VertxOptions에서 표시 방식을 수정 할 수 있습니다.

VertxOptions options = new VertxOptions();
options.setBlockedThreadCheckIntervalUnit( java.util.concurrent.TimeUnit );
options.setBlockedThreadCheckInterval( long );

setBlockedThreadCheckIntervalUnit 및 setBlockedThreadCheckInterval 함수를 사용하면 경고 로그가 반복 표시되는 시간 간격을 설정 할 수 있습니다(default:1000ms).

VertxOptions options = new VertxOptions();
options.setMaxEventLoopExecuteTimeUnit( java.util.concurrent.TimeUnit )
options.setMaxEventLoopExecuteTime( long )

setMaxEventLoopExecuteTimeUnit 및 setMaxEventLoopExecuteTime 함수를 사용하면 경고 로그가 표시되기 시작하는 시간 기준을 설정 할 수 있습니다(default:2000000000ns(2s)).

테스트 케이스: 디폴트

프로퍼티 수정에 앞서 가장 Plain한 프레임워크를 구현 후 성능 밴드를 테스트합니다.

주요한 모듈은 다음 세 가지 입니다.

BlockingEventBusSender	BlockingEventBusReceiver	vert.x-eventloop-thread-0
100ms 간격으로 이벤트 버스로 메시지 송신	이벤트 버스로 Consume 메시지를 처리하되, 요청 한 건에 대해서 300ms 소요	1개의 이벤트 루프 스레드를 실행

기본적으로 Vert.x에서 이벤트 루프 스레드는 애플리케이션이 실행되는 머신의 CPU * 2개만큼 실행됩니다.

이 값을 수정하려면 io.vertx.core.VertxOptions에서 setEventLoopPoolSize 함수를 호출합니다.

/**
* The default number of event loop threads to be used  = 2 * number of cores on the machine
*/
public static final int DEFAULT_EVENT_LOOP_POOL_SIZE = 2 * CpuCoreSensor.availableProcessors();

이벤트 루프 스레드가 1개인 상태에서 차단 코드가 실행(300ms)되면 전체 Task가 딜레이됩니다.

Sender의 메시지 송신 간격은 100ms이지만 Receiver가 실행하는 차단 코드에 의해서 이벤트 루프 스레드가 차단되고 있어 메시지 송신과 메시지 수신이 직렬로 수행됩니다.

로그 상 Sender의 첫 메시지 송신과 두 번째 메시지 송신 간 시간 간격은 약 401ms초(ACK 딜레이 400ms+Send 딜레이 100ms)입니다.

[2023-09-11 17:24:32.185][BlockingEventbusSender      ][@7c5aea68 ][vert.x-eventloop-thread-0] blocking sent(1) 
[2023-09-11 17:24:32.28 ][BlockingEventbusReceiver    ][@60110e0c ][vert.x-eventloop-thread-0] blocking id(1) received(1) 
[2023-09-11 17:24:32.584][BlockingEventbusReceiver    ][@60110e0c ][vert.x-eventloop-thread-0] blocking id(1) received(1) completed(1) 
[2023-09-11 17:24:32.585][BlockingEventbusSender      ][@7c5aea68 ][vert.x-eventloop-thread-0] blocking sent ack(1) 
[2023-09-11 17:24:32.586][BlockingEventbusSender      ][@7c5aea68 ][vert.x-eventloop-thread-0] blocking sent(2)

이벤트 루프 스레드가 1개인 상태는 Vert.x 애플리케이션이 완전히 싱글 스레드로 동작하고 있는 상태를 보여줍니다.

성능 측정을 위해서 Prometheus로 Metrics를 수집하고, Grafana에서 대시보드로 지표를 출력합니다.

Sender의 Task 실행 시간은 평균 0.1ms 이하지만, 이벤트 루프 스레드가 차단되고 있으므로 분 당 실행 횟수는 200건으로 고정되고 있습니다.

마찬가지로 이벤트 루프 스레드를 차단하고 있는 Receiver 역시 분 당 실행 횟수가 200건으로 고정됩니다.

이벤트 루프 스레드	메시지 송신 소요 시간	분 당 메시지 송신 건	메시지 수신 소요 시간	분 당 메시지 수신 건
1개	1ms 이하	200건(100ms Delayed, 10ms Interval)	300ms	200건(300ms Delayed)

테스트 케이스: 이벤트 루프 스레드

이벤트 루프 스레드의 수량을 Vert.x에서 제공하는 디폴트 옵션으로 지정합니다.

이벤트 루프 스레드 수량 조절은 테스트 케이스 : 디폴트를 참고합니다.

이제 Vert.x 애플리케이션이 멀티 스레드로 동작하기 때문에 Receiver의 차단 코드에 의해서 Sender가 차단되지 않습니다.

Sender의 경우 vert.x-eventloop-thread-0, Receiver의 경우 vert.x-eventloop-thread-1 서로 다른 이벤트 루프 스레드에서 태스크가 처리되고 있습니다.

[2023-09-11 18:25:33.103][BlockingEventbusSender      ][@3ec8f506 ][vert.x-eventloop-thread-0] blocking sent(1) 
[2023-09-11 18:25:33.199][BlockingEventbusReceiver    ][@327c29a7 ][vert.x-eventloop-thread-1] blocking id(1) received(1) 
[2023-09-11 18:25:33.204][BlockingEventbusSender      ][@3ec8f506 ][vert.x-eventloop-thread-0] blocking sent(2) 
[2023-09-11 18:25:33.299][BlockingEventbusSender      ][@3ec8f506 ][vert.x-eventloop-thread-0] blocking sent(3) 
[2023-09-11 18:25:33.398][BlockingEventbusSender      ][@3ec8f506 ][vert.x-eventloop-thread-0] blocking sent(4) 
[2023-09-11 18:25:33.5  ][BlockingEventbusReceiver    ][@327c29a7 ][vert.x-eventloop-thread-1] blocking id(1) received(1) completed(1) 
[2023-09-11 18:25:33.5  ][BlockingEventbusSender      ][@3ec8f506 ][vert.x-eventloop-thread-0] blocking sent(5) 
[2023-09-11 18:25:33.501][BlockingEventbusSender      ][@3ec8f506 ][vert.x-eventloop-thread-0] blocking sent ack(1)

Sender의 송신 건수는 늘어났지만, 여전히 Receiver의 이벤트 루프 스레드는 차단되고 있습니다.

다음 테스트 케이스에서는 Receiver의 성능 밴드를 올리는 동시에 이벤트 루프 스레드를 차단하지 않는 방법을 논의합니다.

이벤트 루프 스레드	메시지 송신 소요 시간	분 당 메시지 송신 건	메시지 수신 소요 시간	분 당 메시지 수신 건
16개=(2*CPU Core)	1ms 이하	600건(100ms Delayed, 10ms Interval)	300ms	200건(300ms Delayed)

테스트 케이스: 워커 스레드

버티클에서 태스크가 생성되면, 이벤트 루프 스레드에서 실행됩니다.

기본적으로 모든 태스크는 이벤트 루프 스레드에서 실행되므로 어떤 차단 코드가 포함되게 되면 전체 태크스에 영향을 주게 됩니다.

불가피하게 차단 코드가 실행되어야 하는 경우, Vert.x의 워커 스레드(Worker thread)를 사용하여 이벤트 루프 스레드에서 차단 코드를 분리시킬 수 있습니다.

워커 스레드를 실행하려면 io.vertx.core.DeploymentOptions을 사용하여 버티클을 deployVerticle 합니다. setWorkerPoolName을 지정하고 해당 워커 스레드 풀에서 실행되는 스레드 수량을  setWorkerPoolSize옵션으로 지정합니다. 그리고 워커 스레드에서 실행되는 인스턴스를 setInstances으로 결정합니다.

DeploymentOptions options = new DeploymentOptions();
options.setWorker( true );
options.setWorkerPoolName( String );
options.setWorkerPoolSize( int );
options.setInstances( int );

버티클이 워커 스레드로 실행되었을 때의 흐름도입니다.

Sender는 기존과 동일하게 이벤트 루프 스레드에서 실행됩니다.

Receiver는 이제 이벤트 루프 스레드로부터 독립된 워커 스레드에서 실행됩니다.

워커 스레드 풀에서 여러 개의 인스턴스가 실행되므로, Receiver의 차단 코드는 멀티 스레드로 동작(인스턴스 개수만큼을 병렬 처리)합니다.

[2023-09-11 19:24:38.17 ][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent(1) 
[2023-09-11 19:24:38.281][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent(2) 
[2023-09-11 19:24:38.282][BlockingEventbusReceiver    ][@75a53153 ][vert.x-worker-thread-blocking-eventbus-receiver-2] blocking id(1) received(1) 
[2023-09-11 19:24:38.282][BlockingEventbusReceiver    ][@525a6d3f ][vert.x-worker-thread-blocking-eventbus-receiver-1] blocking id(2) received(1) 
[2023-09-11 19:24:38.371][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent(3) 
[2023-09-11 19:24:38.372][BlockingEventbusReceiver    ][@220b9b6c ][vert.x-worker-thread-blocking-eventbus-receiver-3] blocking id(3) received(1) 
[2023-09-11 19:24:38.47 ][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent(4) 
[2023-09-11 19:24:38.473][BlockingEventbusReceiver    ][@6450d144 ][vert.x-worker-thread-blocking-eventbus-receiver-0] blocking id(4) received(1) 
[2023-09-11 19:24:38.573][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent(5) 
[2023-09-11 19:24:38.583][BlockingEventbusReceiver    ][@75a53153 ][vert.x-worker-thread-blocking-eventbus-receiver-2] blocking id(1) received(1) completed(1) 
[2023-09-11 19:24:38.583][BlockingEventbusReceiver    ][@525a6d3f ][vert.x-worker-thread-blocking-eventbus-receiver-1] blocking id(2) received(1) completed(1) 
[2023-09-11 19:24:38.583][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent ack(1) 
[2023-09-11 19:24:38.584][BlockingEventbusReceiver    ][@75a53153 ][vert.x-worker-thread-blocking-eventbus-receiver-2] blocking id(5) received(2) 
[2023-09-11 19:24:38.584][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent ack(2) 
[2023-09-11 19:24:38.675][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent(6) 
[2023-09-11 19:24:38.676][BlockingEventbusReceiver    ][@525a6d3f ][vert.x-worker-thread-blocking-eventbus-receiver-1] blocking id(6) received(2) 
[2023-09-11 19:24:38.678][BlockingEventbusReceiver    ][@220b9b6c ][vert.x-worker-thread-blocking-eventbus-receiver-3] blocking id(3) received(1) completed(1) 
[2023-09-11 19:24:38.678][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent ack(3) 
[2023-09-11 19:24:38.774][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent(7) 
[2023-09-11 19:24:38.775][BlockingEventbusReceiver    ][@220b9b6c ][vert.x-worker-thread-blocking-eventbus-receiver-3] blocking id(7) received(2) 
[2023-09-11 19:24:38.776][BlockingEventbusReceiver    ][@6450d144 ][vert.x-worker-thread-blocking-eventbus-receiver-0] blocking id(4) received(1) completed(1) 
[2023-09-11 19:24:38.777][BlockingEventbusSender      ][@3225fdfa ][vert.x-eventloop-thread-0] blocking sent ack(4)

이를 지표화해서 확인하면 Receiver의 동시 처리량이 늘어났습니다.

테스트 환경에서는 10개의 워커 스레드가 인스턴스로 실행되었지만, 실제 분 당 처리량은 2000개(분 당 처리량 200개*인스턴스 10개)가 아닌 600개입니다.

Sender의 송신량이 분 당 600개인 것을 고려하면 Receiver가 Sender의 요청량을 초과하여 처리하고 있음을 알 수 있습니다.

이벤트 루프 스레드	워커 스레드	메시지 송신 소요 시간	분 당 메시지 송신 건	메시지 수신 소요 시간	분 당 메시지 수신 건
16개=(2*CPU Core)	10개	1ms 이하	600건(100ms Delayed, 10ms Interval)	300ms	600건(300ms Delayed)

워커 스레드 인스턴스가 스레드 풀보다 큰 경우, 예를 들어 아래와 같은 코드는 오동작의 원인이 될 수 있습니다.

이벤트 루프 스레드의 경우 풀 사이즈 내에서 버티클을 자동 할당하지만, 워커 스레드의 경우 지정된 인스턴스 수량이 풀 사이즈를 초과하는 경우 초과된 인스턴스에서는 스레드가 할당되지 않을 수 있습니다.

DeploymentOptions options = new DeploymentOptions();
options.setWorker( true );
options.setWorkerPoolSize( 10 );
options.setInstances( 20 );
...

테스트 케이스: 워커 스레드+executeBlocking

워커 스레드를 사용하면 차단 코드에 대한 병렬성은 높아지지만, 스레드를 추가로 사용해야 한다는 아쉬움이 있습니다.

차단 코드의 실행 가능성은 간혈적이거나 또는 일시적일 수 있기 때문입니다.

오히려 컨텍스트 스위칭(Context switching)이 빈번하게 발생하여 전체적인 퍼포먼스를 떨어뜨릴 수 있습니다.

버티클 내에서 차단 코드의 실행량이 적은 경우에는 io.vertx.core.Vertx의 exectureBlocking 메소드를 사용 할 수 있습니다.

이때 실행되는 차단 코드는 별도의 스레드에서 실행됩니다.

exectureBlocking 메소드는 boolean ordered 파라미터에 대해서 오버라이드 되어 있습니다.

ordered 파라미터는 디폴트로 true가 지정되는데, 이 경우 동일한 차단 코드에 대해서 직렬로 동작하므로 병렬성을 높이려면 false를 입력하여 사용해야 합니다.

  /**
   * Safely execute some blocking code.
   */
  <T> void executeBlocking(Handler<Future<T>> blockingCodeHandler, boolean ordered, Handler<AsyncResult<@Nullable T>> resultHandler);

  /**
   * Like {@link #executeBlocking(Handler, boolean, Handler)} called with ordered = true.
   */
  <T> void executeBlocking(Handler<Future<T>> blockingCodeHandler, Handler<AsyncResult<@Nullable T>> resultHandler);

콘솔 로그를 확인하면 exectureBlocking 메소드에서 실행되고 있는 차단 코드가 vert.x-worker-thread-N 스레드 풀에서 동작하고 있습니다.

이를 통해 이벤트 루프 스레드에서 벗어나 독립적으로 실행됨을 알 수 있습니다.

[2023-09-11 19:47:50.452][BlockingEventbusSender      ][@1c965db8 ][vert.x-worker-thread-17] blocking sent(34183) 
[2023-09-11 19:47:50.459][BlockingEventbusSender      ][@1c965db8 ][vert.x-worker-thread-16] blocking sent(34184)

지표에서 확인하면 이제 Receiver가 분 당 2000개(분 당 처리량 200개*인스턴스 10개)의 태스크를 처리합니다.

수행 할 수 있는 최대 성능 밴드에 도달한 것을 알 수 있습니다.

Sender 버티클에서 exectureBlocking 메소드를 사용하여 메시지를 송신(기존 차단 코드)하고 있기 때문입니다.

이벤트 루프 스레드	워커 스레드	메시지 송신 소요 시간	분 당 메시지 송신 건	메시지 수신 소요 시간	분 당 메시지 수신 건
16개=(2*CPU Core)	10개	1ms 이하	6000건(100ms Delayed, 10ms Interval)	300ms	2000건(300ms Delayed)

결론 및 정리

• Vertx 애플리케이션의 성능을 최대로 활용하려면 Multi-Reactor 패턴에 대한 이해가 필요합니다.
• 애플리케이션 환경에 따라서차단 코드를 어떻게 병렬 처리하는지가 중요합니다.
• 가장 쉬운 방법은 차단 코드가 실행 될 가능성이 있는 버티클을 워커 스레드로 분리하고 여러 개의 인스턴스로 실행하는 방법입니다.
• 워커 스레드 남용은 더 많은 컨텍스트 스위칭을 발생시키므로 exectureBlocking 메소드를 사용하는 것이 적합 할 수도 있습니다.

테스트 케이스	이벤트 루프 스레드	워커 스레드	메시지 송신 소요 시간	분 당 메시지 송신 건	메시지 수신 소요 시간	분 당 메시지 수신 건
디폴트	1개	-	1ms 이하	200건(100ms Delayed, 10ms Interval)	300ms	200건(300ms Delayed)
이벤트 루프 스레드	16개=(2*CPU Core)	-	1ms 이하	600건(100ms Delayed, 10ms Interval)	300ms	200건(300ms Delayed)
워커 스레드	16개=(2*CPU Core)	10개	1ms 이하	600건(100ms Delayed, 10ms Interval)	300ms	600건(300ms Delayed)
워커 스레드+executeBlocking	16개=(2*CPU Core)	10개	1ms 이하	6000건(100ms Delayed, 10ms Interval)	300ms	2000건(300ms Delayed)