코루틴에서 CPU‐Heavy 태스크를 별도 스레드로 분리 개선 후 테스트 - 100-hours-a-week/5-yeosa-wiki GitHub Wiki

코루틴 코드

async def embed_controller(req: ImageRequest, request: Request) -> JSONResponse:
    """
    이미지 임베딩을 수행하는 컨트롤러입니다.

    Args:
        req: 이미지 파일명 목록을 포함한 요청 객체
        request: FastAPI 요청 객체

    Returns:
        JSONResponse: 성공 메시지와 데이터를 포함한 응답
    """
    logger.info(
        "이미지 임베딩 요청 처리 시작",
        extra={"total_images": len(req.images)},
    )

    image_refs = req.images

    # 1. 이미지 로드
    image_loader = request.app.state.image_loader

    images = await image_loader.load_images(image_refs)

    logger.debug(
        "이미지 로드 완료",
        extra={"loaded_images": len(images)},
    )

    # 2. 모델 및 전처리 로드
    clip_model = request.app.state.clip_model
    clip_preprocess = request.app.state.clip_preprocess
    
    # 직접 메인 스레드에서 실행했던 기존 코드
    # embed_images(
    #     clip_model,
    #     clip_preprocess,
    #     images,
    #     image_refs,
    #     batch_size=DEFAULT_BATCH_SIZE,
    #     device=DEFAULT_DEVICE,
    # )
    
    # 별도의 스레드에서 연산을 수행하도록 분리한 코드
    loop = request.app.state.loop
    task_func = partial(
        embed_images,
        clip_model,
        clip_preprocess,
        images,
        image_refs,
        batch_size=DEFAULT_BATCH_SIZE,
        device=DEFAULT_DEVICE,
    )
    await loop.run_in_executor(None, task_func)

    logger.info(
        "이미지 임베딩 완료",
        extra={"processed_images": len(image_refs)},
    )

    return JSONResponse(
        status_code=201,
        content={"message": "success", "data": None},
    )

1. 테스트 목적

a. 가정

기존 구조에서는 torch 추론 연산이 async def 함수 내부에서 이벤트 루프를 점유한 채 직접 실행되고 있다.
이 구조에서는 동시 요청이 들어와도 순차적으로 처리될 수밖에 없으며, 그 결과 요청 수에 비례해 응답 시간이 선형 증가할 것으로 예상된다.
반면, torch 연산을 run_in_executor() 또는 asyncio.to_thread()로 별도 스레드에서 실행하도록 분리하면, 이벤트 루프가 블로킹되지 않고, 요청이 병렬 처리될 수 있다.

b. 예상 결과

구조 개선 이전에는 요청 수가 증가함에 따라 응답 시간이 선형적으로 증가할 것이다.
구조 개선 이후에는 요청 수가 증가해도 응답 시간 증가 폭이 줄어들고,

여러 요청이 동시에 처리되는 양상을 보일 것이다.
따라서 두 구조 간 응답 시간 차이를 비교함으로써,

비동기 실행 분리 전략의 성능 향상을 수치적으로 입증할 수 있을 것이다.

2. 테스트 설계(기존과 동일)

a. 도구

부하 테스트 도구: k6
테스트 스크립트: thread-separation-test.js

b. 방식

-vus N --iterations N --duration 1s 형태로 테스트 실행

→ N명의 사용자가 동시에 1번씩 요청을 보냄
동시 요청 수(VUs)를 1~5까지 점차 증가
torch 연산은 이미지 30장에 대해 평균 3.5초 정도 걸리는 CPU 연산

c. 요청 형식

POST /api/albums/embedding

{
  "images": ["img001.jpg", ..., "img030.jpg"]
}

3. 테스트 결과

개선 전 결과

동시 요청 수 (VUs) 평균 응답 시간

1 3.68초

2 7.05초

3 10.67초

4 13.48초

5 16.55초

동시 요청 수 (VUs)	평균 응답 시간
1	3.68초
2	7.05초
3	10.67초
4	13.48초
5	16.55초

동시 요청 수 (VUs)	평균 응답 시간
1	4.01s
2	4.15s
3	5.02s
4	6.95s
5	8.43s

병렬로 torch 연산이 처리되기 시작함
응답 시간은 더 이상 선형 증가하지 않음
N개의 요청이 동시에 실행되며, 자원 경쟁만 발생

4. 로그 분석

vus 5명일 때의 전체 로그

2025-05-14 06:58:20.081 | INFO     | fastapi.routing:app:301 - embed 함수 시작
2025-05-14 06:58:20.081 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 시작
2025-05-14 06:58:20,081 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20.096 | INFO     | fastapi.routing:app:301 - embed 함수 시작
2025-05-14 06:58:20.096 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 시작
2025-05-14 06:58:20,096 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20.096 | INFO     | fastapi.routing:app:301 - embed 함수 시작
2025-05-14 06:58:20.096 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 시작
2025-05-14 06:58:20,096 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20.097 | INFO     | fastapi.routing:app:301 - embed 함수 시작
2025-05-14 06:58:20.097 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 시작
2025-05-14 06:58:20,097 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20.097 | INFO     | fastapi.routing:app:301 - embed 함수 시작
2025-05-14 06:58:20.097 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 시작
2025-05-14 06:58:20,097 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20.655 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 시작
2025-05-14 06:58:20,655 INFO    이미지 임베딩 시작
2025-05-14 06:58:20.806 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 시작
2025-05-14 06:58:20,811 INFO    이미지 임베딩 시작
2025-05-14 06:58:21.033 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 시작
2025-05-14 06:58:21,033 INFO    이미지 임베딩 시작
2025-05-14 06:58:21.288 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 시작
2025-05-14 06:58:21,288 INFO    이미지 임베딩 시작
2025-05-14 06:58:21.545 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 시작
2025-05-14 06:58:21,546 INFO    이미지 임베딩 시작
2025-05-14 06:58:28,157 INFO    이미지 임베딩 완료
2025-05-14 06:58:28.158 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 성공
2025-05-14 06:58:28.159 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 성공
2025-05-14 06:58:28.160 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54437 - "POST /api/albums/embedding HTTP/1.1" 201 Created
2025-05-14 06:58:28,391 INFO    이미지 임베딩 완료
2025-05-14 06:58:28.392 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 성공
2025-05-14 06:58:28.393 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 성공
2025-05-14 06:58:28.393 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54438 - "POST /api/albums/embedding HTTP/1.1" 201 Created
2025-05-14 06:58:28,490 INFO    이미지 임베딩 완료
2025-05-14 06:58:28.490 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 성공
2025-05-14 06:58:28.491 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 성공
2025-05-14 06:58:28.491 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54434 - "POST /api/albums/embedding HTTP/1.1" 201 Created
2025-05-14 06:58:28,599 INFO    이미지 임베딩 완료
2025-05-14 06:58:28.600 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 성공
2025-05-14 06:58:28.601 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 성공
2025-05-14 06:58:28.601 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54436 - "POST /api/albums/embedding HTTP/1.1" 201 Created
2025-05-14 06:58:28,695 INFO    이미지 임베딩 완료
2025-05-14 06:58:28.695 | INFO     | concurrent.futures.thread:_worker:83 - embed_images 함수 성공
2025-05-14 06:58:28.710 | INFO     | app.utils.logging_decorator:async_wrapper:61 - embed_controller 함수 성공
2025-05-14 06:58:28.710 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54435 - "POST /api/albums/embedding HTTP/1.1" 201 Created

a. 요청 수신 시각

2025-05-14 06:58:20,081 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20,096 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20,096 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20,097 INFO    이미지 임베딩 요청 처리 시작
2025-05-14 06:58:20,097 INFO    이미지 임베딩 요청 처리 시작

모든 요청이 거의 동시에 수신

→ 개선 전과 동일한 조건

b. 이미지 임베딩 시작/완료 시간

개선 전

요청당 3~3.5초 간격으로 순차 실행

2025-05-14 06:33:10,584 INFO    이미지 임베딩 시작
2025-05-14 06:33:14,300 INFO    이미지 임베딩 완료
2025-05-14 06:33:14,302 INFO    이미지 임베딩 시작
2025-05-14 06:33:17,514 INFO    이미지 임베딩 완료
2025-05-14 06:33:17,516 INFO    이미지 임베딩 시작
2025-05-14 06:33:20,523 INFO    이미지 임베딩 완료
2025-05-14 06:33:20,526 INFO    이미지 임베딩 시작
2025-05-14 06:33:23,504 INFO    이미지 임베딩 완료
2025-05-14 06:33:23,505 INFO    이미지 임베딩 시작
2025-05-14 06:33:26,483 INFO    이미지 임베딩 완료

2025-05-14 06:58:20,655 INFO    이미지 임베딩 시작
2025-05-14 06:58:20,811 INFO    이미지 임베딩 시작
2025-05-14 06:58:21,033 INFO    이미지 임베딩 시작
2025-05-14 06:58:21,288 INFO    이미지 임베딩 시작
2025-05-14 06:58:21,546 INFO    이미지 임베딩 시작
2025-05-14 06:58:28,157 INFO    이미지 임베딩 완료
2025-05-14 06:58:28,391 INFO    이미지 임베딩 완료
2025-05-14 06:58:28,490 INFO    이미지 임베딩 완료
2025-05-14 06:58:28,599 INFO    이미지 임베딩 완료
2025-05-14 06:58:28,695 INFO    이미지 임베딩 완료

0.2~0.3초 간격으로 스레드풀에서 실행 시작

→ 요청 처리 루틴이 동시에 스레드풀에 offload되어 병렬 처리됨

→ 이벤트 루프는 점유되지 않았으며, 각 요청이 바로 처리되기 시작했음을 의미
거의 같은 시간대(28.1~28.7초)에 모두 종료

→ 각각의 요청이 병렬로 수행되었기에 모두 8초 내외의 처리 시간으로 마무리됨

→ 이전처럼 직렬로 3.5초씩 추가되지 않음

c. 응답 시점 비교

개선 전

# 마지막 임베딩 완료 후 전체 응답 반환
2025-05-14 06:33:26,484 INFO    이미지 임베딩 완료
INFO:     211.244.225.166:53665 - "POST /api/albums/embedding HTTP/1.1" 201 Created
INFO:     211.244.225.166:53667 - "POST /api/albums/embedding HTTP/1.1" 201 Created
INFO:     211.244.225.166:53668 - "POST /api/albums/embedding HTTP/1.1" 201 Created
INFO:     211.244.225.166:53666 - "POST /api/albums/embedding HTTP/1.1" 201 Created
INFO:     211.244.225.166:53669 - "POST /api/albums/embedding HTTP/1.1" 201 Created

2025-05-14 06:58:28.160 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54437 - "POST /api/albums/embedding HTTP/1.1" 201 Created
2025-05-14 06:58:28.393 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54438 - "POST /api/albums/embedding HTTP/1.1" 201 Created
2025-05-14 06:58:28.491 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54434 - "POST /api/albums/embedding HTTP/1.1" 201 Created
2025-05-14 06:58:28.601 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54436 - "POST /api/albums/embedding HTTP/1.1" 201 Created
2025-05-14 06:58:28.710 | INFO     | fastapi.routing:app:301 - embed 함수 성공
INFO:     211.244.225.166:54435 - "POST /api/albums/embedding HTTP/1.1" 201 Created

연산 종료 후 순차적으로 반환
비동기로 실행되었으므로 거의 동시에 반환됨

d. 결론: 구조 개선이 성공적으로 작동했음을 입증

이벤트 루프가 점유되지 않음 → embed_images()가 즉시 실행 시작
스레드풀이 병렬 실행을 수용함 → 요청 처리 시간 분산
응답이 한 번에 모여 나감 → 전체 응답 속도 크게 향상

e. 이 로그가 보여주는 핵심

구분	개선 전	개선 후
요청 수신 시각	동시에 수신됨	동시에 수신됨
`embed_images()` 시작	3.5초 단위로 순차 실행됨	0.2~0.3초 간격으로 병렬 실행됨
응답 시각	3.5초 × N 이후 순차 응답	거의 동시에 응답 완료

5. 결과 분석

a. 병목 해소

구조 개선 전에는 요청 수가 늘어날수록 응답 시간이 거의 정확히 3.5초 단위로 선형 증가함
- 예:
  - 1명 → 3.68s
  - 5명 → 16.55s ≈ 3.3s × 5
- 이는 각 요청이 torch 연산을 직렬로 수행했음을 명확히 보여줌
구조 개선 후에는 동시 요청 수가 증가해도 응답 시간 증가폭이 완만하게 유지됨
- 예:
  - 1명 → 4.01s
  - 5명 → 8.43s
  - 증가폭: +4.42s (직렬 처리였다면 +14s 이상 증가했을 것)

b. 성능 향상 정량적 비교 (예시: VUs = 5)

항목	개선 전	개선 후	개선 효과
평균 응답 시간	16.55s	8.43s	약 2배 향상
처리 방식	직렬	병렬 (스레드 분리)	✅ 이벤트 루프 비점유

c. 핵심 인사이트

run_in_executor()를 통해 루프 비점유 구조로 분리하면 병렬성 + 응답성 모두 향상된다는 사실이 실증됨

→ torch 연산과 같은 CPU 바운드 연산은 반드시 이벤트 루프 밖에서 실행해야 한다.

코루틴에서 CPU‐Heavy 태스크를 별도 스레드로 분리 개선 후 테스트 - 100-hours-a-week/5-yeosa-wiki GitHub Wiki

1. 테스트 목적

a. 가정

b. 예상 결과

2. 테스트 설계**(기존과 동일)**

a. 도구

b. 방식

c. 요청 형식

3. 테스트 결과

4. 로그 분석

a. 요청 수신 시각

b. 이미지 임베딩 시작/완료 시간

c. 응답 시점 비교

d. 결론: 구조 개선이 성공적으로 작동했음을 입증

e. 이 로그가 보여주는 핵심

5. 결과 분석

a. 병목 해소

b. 성능 향상 정량적 비교 (예시: VUs = 5)

c. 핵심 인사이트

2. 테스트 설계(기존과 동일)