지난 블로그에서 Kafka 를 활용한 OCR 검수 시스템을 만드는 대략적인 아키텍처를 살펴보았습니다. 이번 글에서는 프로덕션 적용 후 나온 문제점과 해결법을 적어보도록 하겠습니다.

가끔, 매우 긴 웹페이지의 상품 정보를 처리해야 할 일이 있습니다. 가상화 브라우저를 통해 이미지를 캡쳐하고, Google Vision API 로 분석처리를 하는 과정동안 서버 자원을 무한히 사용할 수는 없기 때문에 작업 제한 시간이 걸려있습니다.

작업 제한 시간 처리를 위해 흔히 하던 방식대로 Scheduled ThreadPool 을 생성하고, 해당 쓰레드 안에 캡쳐 처리로직, Vision API 처리 로직을 추가하였습니다. Google Vision Client 는 GRPC 비동기 처리 방식이기 때문에, 당연히 습관처럼 Client 생성 후 shutdown 코드를 집어넣었습니다.


ImageAnnotatorClient vision = ImageAnnotatorClient.create();
try {
    AnnotateImageRequest request = AnnotateImageRequest.newBuilder()
            //.addFeatures(safeSearchFeat)
            .addFeatures(textDetectionFeat)
            .setImage(image)
            .build();
    requests.add(request);

    // Performs label detection on the image file
    BatchAnnotateImagesResponse response = vision.batchAnnotateImages(requests);
    List<AnnotateImageResponse> responses = response.getResponsesList();
    .....
} catch (Exception ex) {
    logger.error("Capture failed.", ex);
    throw ex;
} finally {
    try {
        //clear vision channel
        if (vision != null && !vision.isShutdown()) {
            vision.shutdownNow();
        }
    } catch (Exception ex) {
        logger.warn("Failed to shutdown vision");
    }
}

이 코드는 개발환경에서 잘 돌아갔고, Pre-Production 환경에서도 몇번의 테스트를 거치는 동안 아무런 문제가 발생하지 않았습니다. 그러나 실제 Production 환경에서 수천개의 Job 을 처리하는 과정에서 문제가 발생하기 시작했습니다. 특정한 메소드 실행시 발생하는 에러가 아닌, 불특정한 구간에서 난데없이 나타나는 Exception 이 발생하였습니다.

2019-11-19 13:32:50 -ERROR Exception while executing runnable io.grpc.internal.SharedResourceHolder$2@65aeebb0
io.grpc.netty.shaded.io.netty.channel.ChannelException: eventfd_write() failed: Bad file descriptor

이 에러가 한번 발생하면, 해당 컨테이너는 gRPC 통신의 완전히 기능을 상실하고, 영구히 복구되지 않는 상태로 남아있었습니다.

왜 이런 문제가 나타나는지 구글링을 해 보았지만 원인을 찾을 수 없었고, 결국 gRPC 에서 사용하는 netty 서버에 대해 개념을 학습 한 후에야 해결법을 찾을 수 있었습니다.

Abount Netty

이 문제는 필자가 Netty Non-Bloking IO 에 대해 완전히 무지했기 때문에 잘못된 코딩으로 벌어진 일이었습니다. 아래 그림처럼, Worker thread 를 제어하는 Event-Loop 는 싱글 쓰레드 입니다. 필자의 잘못은 Event-Loop 에 대한 특성을 이해하지 못하고 매번 gRPC 호출시 이것을 종료했다가 다시 생성하는 코드를 작성했기 때문이었습니다.

Normal Case

먼저, 초기에 문제가 없을 시 모습입니다.

모든 Image 들이 적당한 분량을 가지고 있고, 최대 제한시간을 넘어서지 않은 채로 순차적으로 처리가 되고 있습니다. 하단의 검은 막대기는 gRPC 에서 사용하는 Netty Shared Channel 입니다. 이 채널의 Event-Loop 에는 Job1, Job2 가 순차적으로 처리되고 있습니다.

Issue Case

다음은, 이슈가 발생하는 케이스 입니다. 이 케이스는 매우 드믈게 발생하기 때문에 원인 분석이 매우 힘들었습니다.

Job1 은 매우 큰 웹페이지 작업이고, 제한시간이 5분이 넘어가기 때문에 메인 작업 쓰레드에서는 강제로 해당 작업을 종료시켰습니다. 하지만 뒤늦게 호출된 gRPC 호출은 별개의 Event-Loop 쓰레드를 사용하기 때문에 계속 진행됩니다.

뒤이어 시작된 Job2 가 진행됩니다. Event-Loop 에는 Job1 과 Job2 가 공존하고 있습니다. Job1 이 종료될 때 Event-Loop 에 대해 shutdown 을 시키면, Job2 가 종료될 때 shutdown 할 대상이 없으므로 Channel 이 완전히 Broken 상태로 놓이게 됩니다.

해결법

매우 간단합니다. 다음과 같이 vision client 를 싱글레톤으로 전환하고, shutdown 을 호출하지 않고 gracefully 하게 종료되기를 기다리는 것입니다.


private ImageAnnotatorClient vision;

@PostConstruct
public void getClient() throws Exception {
    this.vision = ImageAnnotatorClient.create();
}
...
try {
    .....
} catch (Exception ex) {
    logger.error("Capture failed.", ex);
    throw ex;
}

그럼, 다음과 같이 자연스러운 Event-Loop 의 흐름이 만들어집니다.

Summary

문제에 직면했을 때, 제일 좋은 해결 방법은 해당 문제를 일으키는 원인 및 현상에 대해 우회하는 방식을 택하지 말고, 근본적인 원리를 탐구함으로써 해결하는 방식입니다. 고통스럽고 힘든 과정이지만 한번 체험하고 나면 이것은 단순히 남이 짜놓은 코드 Snippet 을 적당히 사용하여 위기를 넘기는 방식과 비교할 수 없는 경험치를 남길 수 있습니다. 이러한 과정은 온전히 개발자의 자산으로 남게 되며 그 사람 만의 경쟁력이 될 수 있습니다.