파이썬 성능 최적화 - cProfile 프로파일링과 실측 기반 개선 (파이썬 고급 21단원)
이 단원에서 배우는 것
17~20단원에서 logkit 은 로그를 스트리밍으로 파싱하고, 여러 파일을 프로세스로 나눠 돌리고, 엔드포인트를 비동기로 점검하고, 설정을 선언형으로 관리한다. 기능은 다 붙었는데 하루치 로그 처리에 12분이 걸린다. 이 단원은 그 12분을 어디서 줄일지 짐작하지 않고 찾아내는 방법을 다룬다.
timeit·cProfile·tracemalloc으로 시간과 메모리의 병목을 특정한다- 효과가 큰 순서대로 최적화 수단을 적용하고, 매번 다시 측정해 효과 없는 변경을 되돌린다
- C 확장이 값어치를 내는 조건과, 오히려 느려지는 조건을 구분한다
버전은 3.11 이상을 전제한다. 3.11 은 그 자체로 큰 성능 릴리스여서, 3.10 에서 손으로 하던 최적화 중 일부는 이제 인터프리터가 알아서 한다.
왜 필요한가
성능 작업에서 개발자의 직관은 놀랄 만큼 자주 틀린다. 실제로 겪는 순서는 이렇다. "정규식이 느릴 것 같다" → 정규식을 걷어내고 split 으로 바꾼다 → 코드가 두 배 복잡해진다 → 측정하니 3% 빨라졌다. 진짜 시간은 파일을 한 줄씩 읽는 I/O 나, 결과를 리스트에 쌓는 메모리 할당이나, 아무도 의심하지 않던 datetime.strptime 이 먹고 있었다.
더 나쁜 것은 최적화한 코드가 되돌리기 어렵다는 점이다. 읽기 쉬운 코드를 읽기 어려운 코드로 바꿔 놓고 효과가 없으면, 이후 모든 유지보수 비용이 그 대가로 나간다. 그래서 규칙은 하나다. 측정하지 않은 최적화는 하지 않는다. 그리고 최적화한 뒤에는 측정으로 효과를 증명하고, 증명 안 되면 되돌린다.
문법과 예제
측정 도구를 목적별로 나눈다
| 도구 | 답하는 질문 | 비용 |
|---|---|---|
time.perf_counter | 이 블록이 몇 초 걸리나 | 없음. 운영에서도 쓸 수 있다 |
timeit | 이 표현식 두 개 중 뭐가 빠른가 | 없음. 단 마이크로벤치의 함정 주의 |
cProfile | 어느 함수가 시간을 먹나 | 2~4배 느려짐. 상대 비교용 |
tracemalloc | 어디서 메모리를 잡나 | 느려지고 메모리도 더 씀 |
| py-spy (외부) | 운영 중인 프로세스가 지금 뭘 하나 | 거의 없음. 프로덕션 조사용 |
17단원에서 만든 Stage 컨텍스트 매니저가 첫 번째 도구다. 단계별 시간을 상시로 찍어 두면 프로파일러를 꺼내기 전에 범위가 좁혀진다.
1단계: cProfile 로 범인 후보 좁히기
import cProfile
import io
import pstats
import random
import re
LINE = re.compile(r'^(\S+) \S+ \S+ \[[^\]]+\] "(\S+) (\S+)[^"]*" (\d{3}) (\d+|-) (\d+)$')
def make_lines(n: int = 200_000) -> list[str]:
ips = [f"10.0.{i // 254}.{i % 254 + 1}" for i in range(500)]
return [
'%s - - [25/Aug/2026:10:00:00 +0900] "GET /api/orders HTTP/1.1" %d 812 %d'
% (random.choice(ips), random.choice([200, 200, 200, 500]), random.randrange(5, 3000))
for _ in range(n)
]
def slowest_paths(lines: list[str], limit_ms: int) -> list[str]:
hits = []
for line in lines:
m = re.match(
r'^(\S+) \S+ \S+ \[[^\]]+\] "(\S+) (\S+)[^"]*" (\d{3}) (\d+|-) (\d+)$', line
)
if m and int(m.group(6)) >= limit_ms:
hits.append(m.group(3))
return hits
if __name__ == "__main__":
lines = make_lines()
pr = cProfile.Profile()
pr.enable()
slowest_paths(lines, 1000)
pr.disable()
buf = io.StringIO()
pstats.Stats(pr, stream=buf).sort_stats("tottime").print_stats(5)
print(buf.getvalue()) ncalls tottime percall cumtime percall filename:lineno(function)
1 0.096 0.096 0.334 0.334 prof.py:20(slowest_paths)
200000 0.075 0.000 0.075 0.000 {method 'match' of 're.Pattern' objects}
200000 0.053 0.000 0.190 0.000 re/__init__.py:164(match)
200000 0.043 0.000 0.062 0.000 re/__init__.py:330(_compile)
333687 0.037 0.000 0.037 0.000 {method 'group' of 're.Match' objects}읽는 법이 중요하다.
tottime— 그 함수 자체에서 쓴 시간(호출한 함수 제외). 고칠 곳을 찾을 때 보는 값이다.cumtime— 하위 호출 포함. 어느 경로가 비싼지 볼 때 쓴다.sort_stats("tottime")이 기본값이 아니다. 지정하지 않으면 엉뚱한 순서로 나온다.
여기서 눈에 띄는 것은 re/__init__.py:330(_compile) 이 20만 번 불렸다는 것이다. re.match(패턴문자열, ...) 는 내부 캐시를 조회하는데, 그 조회 자체가 20만 번 일어난다. 그리고 group 이 33만 번 불렸다. 고칠 곳 두 개가 나왔다.
2단계: 고치고 다시 측정
def slowest_paths_fast(lines: list[str], limit_ms: int) -> list[str]:
hits = []
append = hits.append # 속성 조회를 루프 밖으로
match = LINE.match # 컴파일된 패턴 + 지역 변수
for line in lines:
m = match(line)
if m is not None and int(m.group(6)) >= limit_ms:
append(m.group(3))
return hitsnaive 0.118s
compiled 0.086s (-27%)27% 를 줄였고 코드는 오히려 읽기 쉬워졌다. 여기까지는 성공이다. 다음으로 "정규식을 돌리기 전에 싼 검사로 걸러내면 더 빠르지 않을까"라는 그럴듯한 아이디어를 시험해 보자.
def slowest_paths_split(lines: list[str], limit_ms: int) -> list[str]:
hits = []
append = hits.append
for line in lines:
if int(line.rsplit(" ", 1)[1]) < limit_ms: # 마지막 필드만 싸게 확인
continue
m = LINE.match(line)
if m is not None:
append(m.group(3))
return hitslimit_ms=1000 (67% 통과): compiled 0.086s / prefilter 0.073s (-15%)
limit_ms=2500 (17% 통과): compiled 0.082s / prefilter 0.035s (-57%)여기서 중요한 것은 이득이 데이터에 달려 있다는 사실이다. 통과율이 67% 일 때는 rsplit 이 매 줄 새 리스트와 문자열을 할당하는 비용이 아낀 정규식 비용을 거의 상쇄해 15% 에 그친다. 통과율이 17% 로 떨어지면 정규식을 여덟 줄 중 일곱 줄에서 건너뛰므로 절반 이하로 준다. 즉 "이 최적화가 옳은가"에 대한 답은 코드가 아니라 운영 데이터의 분포가 정한다. 통과율이 높은 워크로드였다면 코드만 복잡해진 채 15% 를 얻는 셈이라 되돌리는 것이 맞고, 지금처럼 대부분이 걸러지는 워크로드라면 유지할 값어치가 있다. 어느 쪽이든 판단 근거는 짐작이 아니라 내 데이터로 잰 숫자다. 그리고 이 변경을 남긴다면 왜 남기는지를 주석에 적어 둔다. 다음 사람이 "정규식 한 번이면 될 걸 왜 두 번 파싱하지"라고 되돌릴 것이기 때문이다.
효과가 큰 순서
대개 아래 순서로 효과가 크다. 위쪽부터 시도한다.
- 일을 아예 안 하기 — 필요 없는 데이터를 안 읽고, 안 만들고, 안 보낸다. 17단원의
islice, 18단원의 "워커에서 숫자만 돌려주기"가 여기 해당한다. 최적화가 아니라 설계다. - 자료구조 바꾸기 — 아래 실측 참조. 자릿수가 바뀌는 유일한 방법이다.
- I/O 줄이기 — 배치로 읽고 쓴다. DB 라운드트립 1000번을 1번으로.
- 파이썬 코드를 덜 실행하기 — 루프를 C 로 내려보낸다(
join,map, 컴프리헨션,collections). - 미세 조정 — 지역 변수 캐싱,
__slots__. 몇 %. - 병렬화 — 18단원. 코어 수만큼.
- C 확장 — 마지막 수단.
2번의 위력을 보자.
import timeit
setup = """
import random
xs = list(range(20000))
s = set(xs)
targets = [random.randrange(40000) for _ in range(2000)]
"""
print("list in : %.3f ms" % (timeit.timeit("sum(t in xs for t in targets)", setup, number=10) / 10 * 1000))
print("set in : %.3f ms" % (timeit.timeit("sum(t in s for t in targets)", setup, number=10) / 10 * 1000))list in : 114.584 ms
set in : 0.089 ms1,287배다. 지역 변수 캐싱으로는 절대 도달할 수 없는 차이이고, 코드는 오히려 더 짧아진다. 목록에 in 을 쓰는 곳이 루프 안에 있으면 그것부터 고친다.
4번의 대표 사례 둘도 실측으로 확인해 둔다.
s = "parts = ['a' * 20] * 20000"
print("+= : %.1f ms" % (timeit.timeit("out = ''\nfor p in parts: out += p", s, number=20) / 20 * 1000))
print("join: %.1f ms" % (timeit.timeit("''.join(parts)", s, number=20) / 20 * 1000))+= : 0.7 ms
join: 0.1 ms7배 차이지만 절대값이 작다는 데 주목한다. 2만 번 반복해서 0.6ms 를 아꼈다. 이 코드가 루프 밖에 한 번 있다면 고칠 가치가 없다. 배수보다 절대 시간을 봐야 한다.
메모리: tracemalloc
import tracemalloc
tracemalloc.start()
result = slowest_paths_fast(lines, 1000)
current, peak = tracemalloc.get_traced_memory()
print("현재 %.1f MB / 최대 %.1f MB" % (current / 1e6, peak / 1e6))
for stat in tracemalloc.take_snapshot().statistics("lineno")[:3]:
print(stat)
tracemalloc.stop()시간보다 메모리가 문제인 경우가 실제로 더 많다. 컨테이너 메모리 한도에 걸려 OOM Kill 되면 속도는 의미가 없다. @dataclass(slots=True) 는 이 국면에서 값어치가 크다. 인스턴스마다 딕셔너리를 만들지 않으므로 객체 수백만 개일 때 메모리가 절반 이하로 준다. 17단원에서 Entry 에 slots=True 를 붙인 이유다.
캐시: functools.cache
from functools import cache
@cache
def classify(path: str) -> str:
"""경로를 서비스 이름으로 매핑한다. 순수 함수이고 입력 종류가 적다."""
for prefix, service in ROUTES:
if path.startswith(prefix):
return service
return "unknown"12단원에서 데코레이터로 캐시를 직접 만들어 봤는데, 표준 라이브러리가 더 나은 것을 이미 준다. functools.cache 는 3.9 부터 있는 lru_cache(maxsize=None) 의 별칭이다. 조건이 맞으면 효과가 크다. 순수 함수이고, 같은 입력이 반복되고, 입력 종류의 수가 유한할 때다. 로그 경로는 종류가 수십 개인데 호출은 수백만 번이므로 정확히 들어맞는다. 세 조건 중 하나라도 어긋나면 캐시는 메모리만 먹는 짐이 된다.
C 확장은 언제 값어치를 내는가
| 수단 | 쓰는 경우 | 대가 |
|---|---|---|
ctypes | 이미 있는 .so/.dll 을 부른다. 빌드 불필요 | 호출당 오버헤드가 크다 |
cffi | C 헤더가 있는 라이브러리를 안정적으로 부른다 | 빌드 필요 |
| Cython | 기존 파이썬 코드의 뜨거운 루프만 타입을 붙여 컴파일 | 빌드 체인, 휠 배포 |
| PyO3 (Rust) | 새로 쓰는 확장. 메모리 안전성 | 러스트 학습, 빌드 체인 |
여기서 초보가 반드시 데는 지점이 있다. 경계를 넘는 비용이 계산 비용보다 크면 C 가 더 느리다.
import ctypes
import ctypes.util
import timeit
libc = ctypes.CDLL(ctypes.util.find_library("c"))
libc.strtol.restype = ctypes.c_long
libc.strtol.argtypes = [ctypes.c_char_p, ctypes.c_void_p, ctypes.c_int]
print(libc.strtol(b"2310", None, 10)) # 2310
print("ctypes %.1f ms" % (timeit.timeit(lambda: libc.strtol(b"2310", None, 10), number=200_000) * 1000))
print("int() %.1f ms" % (timeit.timeit(lambda: int(b"2310"), number=200_000) * 1000))ctypes 67.6 ms
int() 9.8 msC 함수가 순수 파이썬보다 7배 느리다. strtol 자체는 나노초 단위지만, 인자를 C 타입으로 변환하고 결과를 파이썬 객체로 되돌리는 비용이 매번 든다. C 확장이 이기려면 한 번의 호출 안에서 충분히 많은 일을 해야 한다. 배열 100만 개를 통째로 넘겨 한 번에 처리하는 numpy 가 빠른 이유이고, 값 하나씩 넘기는 코드가 느린 이유다.
C 확장을 고민하기 전에 순서를 지킨다. (1) 알고리즘·자료구조를 고쳤는가 (2) 18단원의 프로세스 병렬화를 썼는가 (3) numpy·polars 처럼 이미 최적화된 라이브러리로 표현할 수 있는가. 세 개를 다 해 보고도 부족할 때에만 직접 확장을 쓴다. 유지보수·크로스 플랫폼 빌드·휠 배포 비용이 성능 이득을 넘는 경우가 흔하다.
pstats 로 결과를 저장·병합하고 호출 관계(print_callers)를 보는 방법은 profile 모듈 공식 문서에 정리돼 있다.
실무에서 자주 틀리는 것
1. 마이크로벤치 결과를 그대로 믿는다
timeit 은 같은 코드를 수만 번 반복한다. 그 과정에서 데이터가 CPU 캐시에 눌러앉고, 분기 예측기가 학습하고, 3.11 의 적응형 인터프리터가 해당 바이트코드를 특수화한다. 실제 서비스에서는 이 조건이 하나도 성립하지 않는다. 캐시는 다른 요청 처리로 밀려나 있고, 데이터는 매번 다르다. 그래서 마이크로벤치에서 20% 빠른 코드가 서비스에서는 차이가 없는 일이 흔하다. 최종 판정은 반드시 전체 파이프라인 실행 시간으로 한다. 그리고 timeit 결과는 평균이 아니라 최소값을 봐야 한다. 평균은 다른 프로세스의 방해를 함께 재기 때문이다.
2. cProfile 이 못 보는 곳에 시간이 있다
cProfile 은 파이썬 함수 호출 단위로 잰다. 그래서 다음은 안 보인다.
- C 안에서 오래 걸리는 일.
sorted()한 줄이 3초여도 항목 하나로만 찍힌다 - 다른 스레드.
cProfile은 자기를 켠 스레드만 본다 - 자식 프로세스. 18단원 구조는 프로파일러가 워커 안을 못 본다
- I/O 대기. 시간은 흘렀는데 함수는 하나도 안 불린 구간
또한 프로파일러는 호출 자체에 오버헤드를 더하므로 작은 함수를 실제보다 비싸 보이게 만든다. 프로파일 결과만 보고 함수를 인라인 전개했다가 실제로는 더 느려지는 경우가 있다. 프로파일링 유무의 전체 시간을 비교해서 왜곡 정도를 먼저 파악해 둔다. 스레드·프로세스·I/O 가 섞인 실제 워크로드라면 py-spy 같은 샘플링 프로파일러가 훨씬 정확한 그림을 준다.
3. lru_cache 를 메서드에 붙여 객체를 못 놓아준다
class Job:
def __init__(self, n: int) -> None:
self.n = n
self.buf = bytearray(1024 * 1024) # 1MB
@lru_cache(maxsize=None) # ← 여기
def score(self) -> int:
return self.n캐시는 클래스에 붙고, 캐시 키에는 self 가 들어간다. 즉 캐시가 인스턴스를 강하게 참조하므로 그 인스턴스는 프로그램이 끝날 때까지 회수되지 않는다. 실제로 weakref 로 확인해 보면 del 하고 GC 를 돌려도 살아 있다. 요청마다 Job 을 만드는 서버라면 메모리가 단조 증가한다. "메모리 누수는 없는데 계속 늘어나요"의 흔한 정체다. 인스턴스 상태에 의존하는 계산은 functools.cached_property 를 쓴다. 이건 값을 인스턴스 __dict__ 에 넣으므로(20단원의 비데이터 디스크립터) 인스턴스와 생사를 같이한다.
4. 병목이 파이썬에 없는데 파이썬을 고친다
12분짜리 배치를 프로파일링했더니 tottime 상위가 전부 소켓 읽기였다면, 파이썬 코드를 아무리 고쳐도 소용없다. 실제 병목은 DB 인덱스가 없어서 매 쿼리가 풀스캔이거나, 로그 파일이 NFS 마운트에 있거나, 로그 레벨이 DEBUG 라서 초당 수만 줄을 디스크에 쓰고 있는 것이다. 파이썬 프로파일러를 열기 전에 time 명령의 real/user/sys 비율부터 본다. user 가 낮고 real 이 크면 파이썬 코드는 범인이 아니다.
스스로 확인하기
- 어떤 함수를 최적화해서
timeit상 40% 빨라졌는데 전체 배치 시간은 그대로다. 원인으로 가능한 것을 두 가지 들어라. - 500만 줄 로그에서 IP 별 요청 수를 세려 한다. 아래 코드의 문제는 무엇이고 어떻게 고치는가?
counts = {} for e in read_log(path): if e.ip not in list(counts.keys()): counts[e.ip] = 0 counts[e.ip] += 1 @cache를 붙여도 되는 함수와 안 되는 함수를 하나씩 들고 이유를 설명하라.
정답
- (1) 그 함수가 전체에서 차지하는 비중이 작다. 전체의 3% 를 먹는 함수를 40% 줄이면 총 개선은 1.2% 다. 암달의 법칙이고, 프로파일에서
tottime비중을 먼저 확인하지 않으면 늘 이 함정에 빠진다. (2) 병목이 파이썬 밖에 있다. I/O 대기나 DB 응답이 대부분이면 CPU 시간을 줄여도 전체 시간은 그대로다. list(counts.keys())가 매 줄마다 전체 키의 새 리스트를 만들고 그 안을 선형 탐색한다. IP 종류가 1만 개면 500만 × 1만 번의 비교가 되어 사실상 끝나지 않는다. 딕셔너리는in이 이미 O(1) 이므로list(...)를 씌우는 순간 그 장점을 통째로 버린 것이다. 고치면 이렇게 된다.from collections import Counter counts = Counter(e.ip for e in read_log(path))Counter는 카운팅 루프가 C 로 구현되어 있어 딕셔너리를 손으로 갱신하는 것보다도 빠르다. 굳이 딕셔너리를 쓴다면counts[e.ip] = counts.get(e.ip, 0) + 1이나defaultdict(int)를 쓴다.- 붙여도 되는 예: 위의
classify(path). 인자가 문자열 하나(해시 가능), 결과가 입력에만 의존, 경로 종류가 수십 개로 유한하다. 붙이면 안 되는 예:fetch_status(path)같이 외부 상태를 읽는 함수. 서버가 죽어서 500 을 반환하기 시작해도 캐시된 200 이 영원히 나온다. 시간이나 파일 내용에 의존하는 함수도 마찬가지다. 인자가 리스트·딕셔너리처럼 해시 불가능한 경우도 애초에TypeError로 막힌다.
다음 단원에서는 지금까지 여러 번 손댄 이 코드가 여전히 맞게 동작하는지를 자동으로 확인하는 장치를 만든다. 최적화는 테스트가 있어야 안심하고 할 수 있다.