커널 레벨에서 fastapi 모델 지연 모니터링 하기

박은서·2025년 11월 8일
PIDebpfmoniteringprocess

MONITERING

목록 보기
1/4

1. 실습 의의: "왜 내 파이썬 서버는 느릴까?"

FastAPI와 Uvicorn으로 구성된 NLP 서비스를 운영하던 중, "과연 내 서비스의 병목은 어디일까?"라는 근본적인 질문에 부딪혔다. 병목이 모델 연산(CPU) 때문일까, 아니면 DB에서 데이터를 읽어오는 I/O 때문일까?

이 질문에 답하기 위해, 리눅스 커널 레벨에서 시스템의 모든 동작을 추적할 수 있는 eBPF(Extended Berkeley Packet Filter) 기반의 프로파일러(ebpf-model-profiler)를 사용해 보기로 결정했다.
https://github.com/cloud-club/08th-ebpf/tree/main/projects/kyj/ebpf-model-profiler
(예지님 감사합니다!! 클클 짱)

하지만 이 과정은 순탄치 않았다.. 운영 중인 서비스는 Nginx 리버스 프록시 뒤에서 20개가 넘는 Uvicorn 워커(프로세스)가 동시에 실행되는 '다중-프로세스' 환경이었고, 사용하려는 프로파일러는 '단일-프로세스'만 추적하도록 설계되어 있었다...

이 글은 Events: 0이라는 절망적인(?) 결과에서 시작해, 프로파일러의 C 코드와 Python 코드를 직접 수정하여 20개가 넘는 자식 프로세스들을 모두 추적하고, 다중 프로세스인 내 서비스 환경에서도 적용된 모습인Total Events: 488이라는 성공적인 결과를 얻기까지의 모든 과정을 담은 튜토리얼이다!

2. 실습을 이해하기 위한 OS/네트워크 지식

이 실습을 100% 이해하기 위해선, 내가 사용한 도구와 환경의 원리를 깊게 알 필요가 있었다.

OS/커널 지식

  • eBPF (Extended Berkeley Packet Filter)
    • 원리: 리눅스 커널 코드의 변경 없이, 커널 내에서 안전하게 샌드박스화된 프로그램을 실행할 수 있게 해주는 기술이다. "커널에 설치하는 이벤트 리스너"로 생각할 수 있다.
    • 동작: read, write 같은 특정 시스템 콜(Syscall)이 호출되는 순간(kprobe)에 eBPF 코드가 실행되어, "A 프로세스가 read를 호출했음" 같은 정보를 수집할 수 있다.
  • BCC (BPF Compiler Collection)
    • 원리: eBPF는 C로 작성해야 해서 매우 복잡하다. BCC는 이 과정을 Python이나 C++로 쉽게 할 수 있도록 도와주는 툴킷이다. 우리가 수정한 .c 파일과 .py 파일이 바로 이 BCC 툴킷의 일부였다.
  • PID와 PPID (프로세스 ID와 부모 프로세스 ID)
    • PID: 모든 프로세스가 갖는 고유한 번호이다.
    • PPID: "나를 실행시킨" 부모 프로세스의 번호이다. 이것이 이번 실습의 핵심 키였다. pstree는 이 PID와 PPID의 관계를 시각적으로 보여주는 도구이다.
  • 시스템 콜 (Syscall)
    • 원리: 애플리케이션(FastAPI)이 디스크 읽기, 네트워크 전송 등 커널의 도움이 필요한 작업을 요청할 때 사용하는 공식적인 "주문서"이다.
    • 예시: read (파일 읽기), write (파일 쓰기), sendto (네트워크 데이터 전송). 우리는 이 "주문서"가 처리되는 데 걸리는 시간을 측정했다.
  • sudo와 가상 환경(venv)의 충돌
    • 문제: venv를 활성화하면 ubuntu 유저의 PATH가 바뀐다. 하지만 sudo는 명령어를 root 유저로 실행한다. root 유저는 venv의 존재를 모르기 때문에 command not found 오류가 발생했다.
    • 해결: sudo ./venv/bin/python3처럼, sudo 명령어를 사용할 때에는sudo에게 venv 안의 파이썬 실행 파일의 절대 경로를 알려주어 해결했다.
  • C 컴파일과 C_INCLUDE_PATH
    • 문제: BCC가 C 코드를 컴파일할 때, sudo 환경에서는 common.h 같은 헤더 파일의 경로를 잃어버렸다. (fatal error: 'common.h' file not found)
    • 해결: C_INCLUDE_PATH=$(pwd)/src/ebpf라는 환경 변수를 설정하여, C 컴파일러에게 "헤더 파일은 이 폴더 안에 있다"라고 명시적으로 알려주었다.

애플리케이션/네트워크 지식

  • Nginx (리버스 프록시)
    • 역할: "수신 데스크" 또는 "교통 경찰"이라고 볼 수 있다. 모든 외부 요청(HTTPS, 443 포트)을 Nginx가 먼저 받는다.
    • 동작: 301 Moved Permanently 오류에서 봤듯이, http:// (80) 요청을 https:// (443)로 강제 리디렉션하는 역할도 한다.
  • Uvicorn (애플리케이션 서버)
    • 역할: "실제 일꾼". Nginx가 넘겨준 요청을 받아 FastAPI 코드를 실행하고 결과를 반환한다.
  • 다중-프로세스 (Multi-Process)와 로드 밸런싱
    • 이것이 모든 문제의 원인이었다.
    • pstree를 보니, python(매니저) -> uvicorn(수석 일꾼) -> {uvicorn}(진짜 일꾼 20+명) 구조였다.
    • Nginx는 요청이 올 때마다 20명이 넘는 "진짜 일꾼" 중 가장 한가한 한 명에게 일을 분배(로드 밸런싱)한다.
    • 우리가 "일꾼 1"의 PID만 추적하면, Nginx가 "일꾼 2"에게 일을 주기 때문에 Events: 0이 떴던 것이다.

실습

※ 해당 서버는 aws 비용 이슈로 곧 내릴 예정이라 ㅎㅎ.. 귀찮아서 ip를 가리진 않았다..

1단계: 설치와 끝없는 오류 (디버깅)

최초 설치 과정에서 수많은 오류를 만났다...

  • ERROR: No matching distribution found for bcc
    • 원인: bcc는 pip가 아닌 apt로 설치해야 하는 시스템 라이브러리이다.
    • 해결: sudo apt-get install bpfcc-tools ...로 설치 후, requirements.txt에서 bcc 라인을 주석 처리했다.
  • sudo: ebpf-profiler: command not found
    • 원인: sudo가 venv 경로를 인식하지 못했다.
    • 해결: sudo -E가 실패하여, sudo ./venv/bin/python3 -m src.cli처럼 venv 안의 파이썬을 절대 경로로 직접 실행했다.
  • fatal error: 'common.h' file not found
    • 원인: sudo 환경에서 C 컴파일러가 헤더 파일 경로를 잃었다.
    • 해결: sudo C_INCLUDE_PATH=$(pwd)/src/ebpf ... 환경 변수를 추가했다.
  • error: cannot call non-static helper function
    • 원인: 프로파일러의 C 코드가 최신 리눅스 커널의 엄격한 규칙과 호환되지 않았다.
    • 해결: src/ebpf/syscall_tracer.c 파일의 trace_syscall_enter 함수 정의부 앞에 static inline을 추가했다.
  • AttributeError: 'BPF' object has no attribute 'ctype'
    • 원인: 프로파일러의 Python 코드가 오래된 bcc API를 사용했다.
    • 해결: src/collector/tracer.py 파일의 .ctype을 Python 내장 ctypes 모듈을 사용하도록 수정했다. (import ctypes as ct 추가, ct.c_uint(...)로 변경)

경고는 있지만 일단 시작..

부하 테스트


이것도 하고 스웨거로도 울 서버에 여러 api 요청들을 보냈다.

2단계: "Events: 0" (잘못된 PID 추적)

모든 오류를 고쳤지만, 결과는 Total Events: 0이었다.


root가 내가 띄운 서버의 PID를 나타내는 것이고, 아래 ubuntu는 내가 grep 명령어를 친 순간 실행된 프로세스의 PID를 나타낸다. root의 PID는 불변하지만 ubuntu의 PID는 계속 변하고 있는 것을 볼 수 있었다.

하지만 이 root PID조차 "진짜"가 아니었다.


아아.. 알고 보니 python(362284)는 "매니저"였고, uvicorn(362406)이 "수석 일꾼", 그 밑의 {uvicorn}(362408...) 20여 개가 "진짜 일꾼"이었다. Nginx가 요청을 20명에게 분산시키니, "일꾼 1"만 감시해서는 아무것도 잡히지 않았던 것이다..!!!!!!!!

3단계: C 코드 수정 (자식 프로세스 추적)

이 문제를 해결하기 위해, "일꾼"(PID)뿐만 아니라 그 "일꾼의 부모"(PPID)도 추적하도록 프로파일러의 C 코드를 수정했다.

nano src/ebpf/syscall_tracer.c를 열어 trace_syscall_enter 함수와 9개의 모든 _exit 함수의 should_trace(pid) 검사 로직을 다음과 같이 변경했다.

// (수정 전)
// if (!should_trace(pid)) {
//     return 0;
// }

// (수정 후)
// "현재 PID"가 추적 대상이 아니면, "부모 PID"도 검사!
if (!should_trace(pid)) {
    struct task_struct *task = (struct task_struct *)bpf_get_current_task();
    u32 ppid = 0;
    bpf_probe_read_kernel(&ppid, sizeof(ppid), &task->real_parent->tgid);

    if (!should_trace(ppid)) {
        return 0; // 둘 다 아니면 무시
    }
}

4단계: 최종 테스트 및 결과

  1. [터미널 A] 프로파일러 시작: C 코드와 Python 코드가 모두 수정된 상태에서, "수석 일꾼"의 PID(362406)를 추적하도록 start 명령어를 실행하고 켜 둔다.

    (venv) $ sudo C_INCLUDE_PATH=$(pwd)/src/ebpf ./venv/bin/python3 -m src.cli start --pid 362406
...
INFO - Tracing started. Press Ctrl+C to stop.

  2. [터미널 B] 부하 테스트: 스웨거나 curl을 이용해 HTTPS API를 10~20회 호출한다.

    $ curl -k "https://<EC2_IP>/api/articles/search?query=test"

  3. [터미널 A] 결과 확인: 부하 테스트 후, 터미널 A로 돌아와 Ctrl+C를 누른다.

    참고: export 명령어는 작동하지 않았다..
    export 명령어는 start가 실행 중일 때(터미널 A) 다른 터미널(터미널 C)에서 실시간 데이터를 가져오는 명령어이다. 하지만 복잡한 sudo와 venv 환경 때문에 프로세스 간 통신(IPC)에 실패하여 Note: This command requires... (데이터 없음) 오류만 발생한 것 같다.

    하지만 start 명령어 자체는 Ctrl+C로 종료될 때, 수집한 통계를 스스로 요약 출력하는 기능이 있었다.

최종 결과:
Ctrl+C를 누르자, 통계가 터미널 A에 출력되었다.

Summary:

  • Total Events: 488
  • Unique Syscalls: 2 (아래를 보면 read, write만 잡혔다)
  • Average Latency: 69us (평균 지연 시간)

Top 10 syscalls by total time:

  • read: 28.85ms (276 calls)
  • write: 5.01ms (212 calls)

분석:
이 요약은 스웨거로 API를 호출하는 동안, 20명이 넘는 "진짜 일꾼"(uvicorn)들이 총 488번의 read/write 시스템 콜을 발생시켰으며, 가장 시간이 많이 걸린 작업은 read(디스크/네트워크 읽기)였음을 명확하게 보여준다.

서비스 느림 의심되는 원인에 대한 모니터링 진행
로그인 1회
서비스 이용 중 병목이 직접 체감됐던 의미기반 검색 api 5회 호출

profile
박은서
다음 포스트

AWS CloudWatch와 Lambda로 SLO 측정 및 장애 알림 자동화 파이프라인 구축기

0개의 댓글