es_rejected_execution_exception 처리하기

---

아래 오류 로그는 사내에서 운영하고 있는 ES 클러스터에서 reindex를 진행하면서 발생한 에러 로그입니다.

(아래 로그는 reindex task id를 받아 확인한 내용입니다.)

해당 에러를 처리하기 위해 트러블 슈팅 한 내용을 적어보려고 합니다.

{
    "shard" : -1,
    "status" : 429,
    "reason" : {
        "type" : "es_rejected_execution_exception",
        "reason" : "rejected execution of org.elasticsearch.common.util.concurrent.TimedRunnable@79b3110f on QueueResizingEsThreadPoolExecutor[name = es7/search, queue capacity = 1000, min queue capacity = 1000, max queue capacity = 1000, frame size = 2000, targeted response rate = 1s, task execution EWMA = 11.6ms, adjustment amount = 50, org.elasticsearch.common.util.concurrent.QueueResizingEsThreadPoolExecutor@18b50ea1[Running, pool size = 49, active threads = 49, queued tasks = 1057, completed tasks = 8519691945]]"
    }
},


# 로그 상세보기.
[
    name = es7/search, 
    queue capacity = 1000, 
    min queue capacity = 1000, 
    max queue capacity = 1000, 
    frame size = 2000, 
    targeted response rate = 1s, 
    task execution EWMA = 11.6ms, 
    adjustment amount = 50, 
    org.elasticsearch.common.util.concurrent.QueueResizingEsThreadPoolExecutor@18b50ea1
    [
        Running, 
        pool size = 49, 
        active threads = 49, 
        queued tasks = 1057, 
        completed tasks = 8519691945
    ]
]

 

reindex가 완료되는 시점에 로그를 확인한 후 하나의 실패 로그가 있어도 실패 처리를 하게 됩니다.

주말에 한번 실행되는 스케줄이기 때문에 몇 주간 실패 로그에 대해서 분석해 보았습니다.

해당 로그가 발생하는 노드들도 매번 달랐고 동일한 시간대에 발생하는 것도 아니었습니다.

 

먼저 클러스터에 설정된 thread_pool 설정을 확인해 보았습니다.

GET _cluster/settings?include_defaults=true

max_queue_size : 검색 작업을 대기시키는 큐의 최대 크기

queue_size : 대기열 크기

size : 스레드 풀의 크기

auto_queue_frame_size : 대용량 검색 요청을 처리할 때 큰 작업을 작은 프레임으로 분할하여 처리하는 크기

target_response_time : 검색 작업에 대한 목표 응답 시간

min_queue_size : 최소 대기열

"search" : {
	"max_queue_size" : "1000",
	"queue_size" : "1000",
	"size" : "49",
	"auto_queue_frame_size" : "2000",
	"target_response_time" : "1s",
	"min_queue_size" : "1000"
},

 

로그에서도 확인 가능하지만 search_reject 로그를 기록하기 때문에 모니터링 도구에서 발생시간과 노드들을 알 수 있었습니다.

 

#search reject 확인
GET /_cat/thread_pool/search?v&s=node_name:asc

 

로그를 읽어보면 queue capacity는 1000으로 설정되어 있지만, queued tasks에는 요청이 1000건이 넘은 1057건 들어온 걸로 보입니다. 큐의 허용범위보다 더 많이 들어와서 생긴 에러 로그로 파악했고 해결 방법으로는 queue의 허용 범위를 늘리거나, reindex 요청 개수를 줄이는 방법을 생각해 봤습니다.

---

 

첫 번째는 queue_size를 증가시키는 방법입니다.

 

queue_size를 증가시켜 쌓아 놓을 수 있는 양을 증가시키는 방법입니다.

다만 queue_size가 커진다고 해서 병렬성이 증가하는 것은 아니고 메모리만 증가하는 부작용이 생길 수 있습니다.

그리고 es 클러스터를 재기동해야 하기 때문에 바로 적용하는데 어려움이 있어 다른 방법을 선택했습니다.

 

아래는 동적으로 queue_size를 변경하는 방법입니다.

  curl -X PUT "http://localhost:9200/_cluster/settings" -H "Content-Type: application/json" -d '{
      "persistent": {
          "thread_pool.search.queue_size": 2000
      }
  }'

 

두 번째 방법은 bulk size를 늘리는 방법입니다.

bulk size를 늘려 요청 개수를 줄이는 방법을 생각했습니다.

해당 방법은 적용하기 쉬워 바로 적용해 봤고 몇 주간 실패 없이 성공했습니다.

POST /_reindex?wait_for_completion=false&slices=auto
{
  "source": {
    "size": 1000,
    "index": "source-index"
  },
  "dest": {
    "index": "target-index"
  }
}

 

세 번째 방법은 slice 수를 줄이는 방법입니다.

두 번째 방법과 동일하게 병렬 처리 수를 줄여 요청 개수를 줄이는 방안입니다.

두 번째 방법도 종종 실패해서 추가적으로 세팅했습니다.

tasks 로그에 slice수가 나와있어서 점차 줄여보았고 성공하고 있습니다.

POST /_reindex?wait_for_completion=false&slices=15
{
  "source": {
    "size": 5000,
    "index": "source-index"
  },
  "dest": {
    "index": "target-index"
  }
}

 

이후 같은 로그로 실패한다면 Cluster 설정인 queue_size를 변경해야 할 거 같습니다.