Đo và tối ưu hiệu năng Python: timeit, cProfile, py-spy và quy trình tối ưu

“Premature optimization is the root of all evil.” - Donald Knuth

Câu trích dẫn này thường bị hiểu sai thành “đừng quan tâm tới hiệu năng”. Ý thật của nó là: đừng tối ưu khi chưa đo. Lập trình viên - kể cả người rất giỏi - đoán sai chỗ chậm của chương trình trong phần lớn trường hợp. Bài này trình bày một quy trình có phương pháp: đo, tìm đúng điểm nóng, sửa, rồi đo lại.

Trong bài này, bạn sẽ học:

• Đo thời gian đúng cách với time.perf_counter và timeit - và những sai lầm khi đo
• Tìm điểm nóng với cProfile và pstats
• Profile chương trình đang chạy trên production với py-spy
• Đo bộ nhớ: tracemalloc, memray
• Case study: tối ưu một hàm xử lý log từ 1.1 giây xuống 0.057 giây
• Các kỹ thuật tối ưu, xếp theo mức độ hiệu quả

Quy trình tối ưu

1. Xác định mục tiêu      "API phải trả lời dưới 200ms", không phải "nhanh hơn"
2. Đo hiện trạng          có con số làm mốc (baseline)
3. Profile                tìm 10% code chiếm 90% thời gian
4. Sửa ĐIỂM NÓNG NHẤT      một thay đổi mỗi lần
5. Kiểm tra kết quả đúng   test vẫn pass, output không đổi
6. Đo lại                  so với baseline; chưa đạt mục tiêu thì quay lại bước 3

Bước 5 hay bị bỏ qua: một phiên bản “nhanh hơn 10 lần” nhưng cho kết quả sai là vô giá trị.

Đo thời gian đúng cách

time.perf_counter() cho đoạn code dài

import time

start = time.perf_counter()
total = sum(i * i for i in range(1_000_000))
elapsed = time.perf_counter() - start
print(f"{elapsed:.3f}s")

• Dùng perf_counter(), không dùng time.time(): time.time() là đồng hồ hệ thống, có thể nhảy khi đồng bộ NTP và độ phân giải thấp hơn.
• time.process_time() chỉ tính thời gian CPU của tiến trình (không tính lúc ngủ/chờ I/O) - hữu ích để phân biệt CPU-bound và I/O-bound (xem bài Chọn mô hình đồng thời).

timeit cho đoạn code ngắn

Đo một đoạn code chỉ mất vài micro-giây bằng perf_counter cho kết quả rất nhiễu. timeit chạy code hàng nghìn lần, tắt GC trong lúc đo, và chọn bộ đếm thời gian chính xác nhất:

$ python -m timeit "'-'.join(str(n) for n in range(100))"
50000 loops, best of 5: 7.43 usec per loop

$ python -m timeit "'-'.join([str(n) for n in range(100)])"
50000 loops, best of 5: 6.01 usec per loop

$ python -m timeit -s "data = list(range(1000))" "sum(data)"
100000 loops, best of 5: 2.61 usec per loop

Để ý kết quả thứ hai: join nhận list nhanh hơn nhận generator, vì join cần biết trước tổng độ dài nên sẽ tự chuyển generator thành list - generator chỉ thêm chi phí. -s là phần setup (chạy một lần, không tính giờ). Trong code:

import timeit

setup = "data = list(range(10_000)); target = 9_999"
t_list = timeit.timeit("target in data", setup=setup, number=1_000)
t_set = timeit.timeit("target in s", setup=setup + "; s = set(data)", number=1_000)
print(f"list: {t_list:.4f}s  set: {t_set:.6f}s")

Những sai lầm thường gặp khi đo:

• Đo lần chạy đầu tiên: lần đầu bao gồm import, khởi tạo cache, “làm nóng” specializing interpreter (xem bài Bytecode). Chạy nhiều lần và lấy giá trị tốt nhất hoặc trung vị.
• Để máy làm việc khác: trình duyệt, IDE đang index… gây nhiễu. Đo nhiều lần, so sánh tương đối.
• Đo dữ liệu quá nhỏ: thuật toán O(n²) có thể nhanh hơn O(n log n) khi n = 10. Đo với kích thước dữ liệu thật.
• Bị “tối ưu hoá mất”: timeit("1 + 2") đo gần như không gì vì hằng số đã được tính sẵn lúc biên dịch.
• Micro-benchmark không phản ánh thực tế: code nhanh hơn 20% trong vòng lặp riêng lẻ có thể chẳng ảnh hưởng gì nếu nó chỉ chiếm 1% tổng thời gian.

Tìm điểm nóng với cProfile

cProfile (thư viện chuẩn) ghi lại mọi lời gọi hàm: gọi bao nhiêu lần, mất bao lâu.

$ python -m cProfile -s tottime my_script.py

Hoặc chỉ profile một đoạn code (3.8+):

import cProfile
import pstats

with cProfile.Profile() as prof:
    main()                                  # hàm cần đo

stats = pstats.Stats(prof)
stats.sort_stats("tottime").print_stats(10) # 10 hàm tốn thời gian nhất
stats.dump_stats("profile.out")             # lưu lại để xem bằng công cụ trực quan

Cách đọc bảng kết quả:

Cột	Ý nghĩa
ncalls	số lần gọi
tottime	thời gian trong chính hàm đó, không tính các hàm nó gọi
cumtime	thời gian tính cả các hàm con
percall	thời gian trung bình mỗi lần gọi

• Sắp theo tottime để tìm hàm tự nó chậm.
• Sắp theo cumtime để thấy nhánh nào của chương trình tốn thời gian nhất.
• Một hàm nhanh nhưng ncalls lên tới hàng triệu thường là manh mối: có thể gọi ít lần hơn không?

Xem trực quan: pip install snakeviz rồi snakeviz profile.out để có biểu đồ dạng “mặt trời” trong trình duyệt.

Lưu ý: cProfile làm chương trình chậm đi đáng kể (mỗi lời gọi hàm đều bị ghi lại) và chỉ cho biết hàm nào chậm, không cho biết dòng nào trong hàm. Với chi tiết từng dòng, dùng line_profiler (thư viện ngoài, decorator @profile + lệnh kernprof -l -v script.py).

Case study: tối ưu hàm tạo báo cáo từ log

Một hàm đọc 200.000 dòng log dạng 2026-09-14 user123 python 250ms, bỏ qua các user bị cấm, và tính tổng thời gian theo ngôn ngữ:

import random
import re

random.seed(42)
WORDS = ["python", "java", "rust", "go", "kotlin", "swift", "dart", "ruby"]
LOGS = [f"2026-09-{random.randint(1, 30):02d} user{random.randint(1, 5000)} "
        f"{random.choice(WORDS)} {random.randint(1, 999)}ms" for _ in range(200_000)]
BANNED = [f"user{i}" for i in range(0, 5000, 7)]

def parse(line):
    m = re.match(r"(\S+) (\S+) (\S+) (\d+)ms", line)
    return m.group(1), m.group(2), m.group(3), int(m.group(4))

def build_report(lines):
    report = ""
    totals = {}
    for line in lines:
        day, user, lang, ms = parse(line)
        if user in BANNED:
            continue
        totals[lang] = totals.get(lang, 0) + ms
    for lang in sorted(totals):
        report += f"{lang}: {totals[lang]}\n"
    return report

Bước 1 - baseline: build_report(LOGS) mất 1.10s.

Bước 2 - profile:

import cProfile, pstats

with cProfile.Profile() as prof:
    build_report(LOGS)
pstats.Stats(prof).sort_stats("tottime").print_stats(5)

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.995    0.995    1.414    1.414 report.py:14(build_report)
   200000    0.133    0.000    0.401    0.000 report.py:10(parse)
   800000    0.084    0.000    0.084    0.000 {method 'group' of 're.Match' objects}
   200000    0.065    0.000    0.065    0.000 {method 'match' of 're.Pattern' objects}
   200000    0.055    0.000    0.184    0.000 re/__init__.py:164(match)

Nhiều người sẽ đoán regex là thủ phạm. Nhưng số liệu nói khác: 0.995s nằm trong chính build_report (tottime), còn toàn bộ phần parse chỉ 0.4s. Trong build_report không gọi hàm nào khác đáng kể… ngoại trừ user in BANNED - một phép toán, không phải lời gọi hàm, nên nó không hiện thành dòng riêng. BANNED là list 715 phần tử → mỗi dòng log phải so sánh tuần tự tới 715 lần.

Bước 3 - sửa điểm nóng nhất:

BANNED_SET = set(BANNED)       # tra cứu O(1) thay vì O(n)
# ...
        if user in BANNED_SET:

Kết quả: 0.162s - nhanh gấp 7 lần, chỉ đổi một dòng.

Bước 4 - profile lại, bây giờ parse với regex mới là phần lớn. Dữ liệu có định dạng cố định, phân tách bằng khoảng trắng → str.split() (chạy trong C) đủ dùng. Đồng thời thay report += bằng "".join(...):

def build_report_fast(lines):
    totals = {}
    for line in lines:
        day, user, lang, ms = line.split()
        if user in BANNED_SET:
            continue
        totals[lang] = totals.get(lang, 0) + int(ms[:-2])   # bỏ hậu tố "ms"
    return "".join(f"{lang}: {totals[lang]}\n" for lang in sorted(totals))

Kết quả: 0.057s. Kiểm tra build_report_fast(LOGS) == build_report(LOGS) → True.

Phiên bản	Thời gian	Thay đổi
Ban đầu	1.104s
list → set	0.162s	7×
regex → split, join	0.057s	19× so với ban đầu

Bài học rút ra:

1. Chỗ chậm nhất không phải chỗ ta đoán (regex) mà là một lỗi chọn cấu trúc dữ liệu.
2. Cải thiện lớn nhất đến từ độ phức tạp thuật toán (O(n) → O(1) cho mỗi lần tra), không phải từ micro-optimization.
3. Mình cũng thử thay dict.get bằng collections.Counter cho gọn - nó chậm hơn một chút (0.064s). Luôn đo, kể cả khi thay đổi “trông có vẻ” tốt hơn.

Profile chương trình đang chạy: py-spy

cProfile phải được bật từ trước và làm chậm chương trình. Khi server production đột nhiên chiếm 100% CPU, bạn cần nhìn vào ngay lúc đó. py-spy là sampling profiler: nó đọc stack của tiến trình Python từ bên ngoài vài trăm lần mỗi giây, không cần sửa code, gần như không làm chậm chương trình.

$ pip install py-spy

# Xem như lệnh "top": hàm nào đang chiếm CPU
$ py-spy top --pid 12345

# In stack hiện tại của mọi thread (tuyệt vời khi chương trình bị treo/deadlock)
$ py-spy dump --pid 12345

# Ghi 30 giây rồi xuất flame graph
$ py-spy record -o profile.svg --pid 12345 --duration 30

(Trên macOS/Linux có thể cần sudo để đọc bộ nhớ của tiến trình khác.)

Flame graph đọc như sau: trục ngang là tỉ lệ thời gian (không phải thời gian tuần tự), mỗi tầng là một mức lời gọi hàm. Những “khối rộng” ở trên cùng là nơi CPU thực sự tiêu tốn thời gian.

Các lựa chọn khác: Scalene (profile cả CPU, bộ nhớ, và phân biệt thời gian trong Python với trong code C), Austin. Từ Python 3.12, CPython hỗ trợ perf của Linux (python -X perf) để thấy cả hàm Python lẫn hàm C trong cùng một profile.

Đo bộ nhớ

• tracemalloc (thư viện chuẩn): dòng code nào cấp phát bao nhiêu - xem bài Bộ cấp phát bộ nhớ và GC.
• memray (Bloomberg): theo dõi mọi lần cấp phát kể cả trong extension C, xuất flame graph bộ nhớ: memray run script.py rồi memray flamegraph output.bin.
• Đỉnh bộ nhớ (peak) thường quan trọng hơn bộ nhớ lúc cuối: một hàm đọc cả file 2 GB vào RAM rồi giải phóng vẫn làm server bị OOM kill.

Các kỹ thuật tối ưu, theo thứ tự hiệu quả

1. Thuật toán và cấu trúc dữ liệu (lợi ích: 10× - 1000×)

Tình huống	Thay bằng
x in list trong vòng lặp	set / dict
Tìm kiếm trên dãy đã sắp xếp	bisect
list.pop(0) / insert(0, x)	collections.deque
Sắp xếp để lấy vài phần tử lớn nhất	heapq.nlargest
Tính lại cùng một giá trị nhiều lần	functools.cache, biến trung gian
Vòng lặp lồng nhau so khớp hai danh sách	dict làm chỉ mục (index) - O(n·m) → O(n + m)
N+1 truy vấn database	Một truy vấn gom (batch / JOIN)

Xem List và Tuple, Dict và Set, functools/itertools/heapq.

2. Để C làm vòng lặp (lợi ích: 2× - 100×)

• Hàm built-in: sum, min, max, sorted, any, all, map, str.join, str.split, str.translate.
• List/dict/set comprehension thay cho vòng lặp append.
• NumPy / Pandas / Polars cho dữ liệu số dạng mảng/bảng - vector hoá thay vì lặp từng phần tử có thể nhanh hơn 10-100 lần.

3. Làm ít việc hơn (lợi ích: tuỳ trường hợp)

• Lười: generator, itertools - không tính những gì không dùng tới.
• Dừng sớm: any() dừng ngay khi gặp phần tử đúng; break khi đã tìm thấy.
• Cache: kết quả truy vấn, kết quả tính toán, regex đã biên dịch.
• Gom lô (batch): gửi 1 request 1000 bản ghi thay vì 1000 request.

4. Đồng thời và song song

I/O-bound: thread hoặc asyncio. CPU-bound: multiprocessing. Xem Chọn mô hình đồng thời.

5. Đổi công cụ thực thi

Khi đã tối ưu hết mức trong Python mà vẫn chưa đủ:

• Nâng cấp phiên bản Python: 3.11 nhanh hơn 3.10 khoảng 25%, các bản sau tiếp tục cải thiện - thường là “tối ưu miễn phí”.
• PyPy: trình thông dịch có JIT, rất nhanh với code Python thuần nhiều vòng lặp; tương thích kém hơn với một số extension C.
• Numba: decorator @njit biên dịch hàm tính toán số (NumPy) sang mã máy.
• Cython / mypyc: biên dịch module Python (có type hint) thành extension C.
• Viết extension bằng Rust (PyO3) cho phần lõi nóng nhất - cách mà Pydantic v2, Polars, Ruff đạt tốc độ cao.

6. Micro-optimization (lợi ích: vài %)

Gán method vào biến cục bộ, tránh tra thuộc tính trong vòng lặp… Như bài Bytecode đã chỉ ra, nhiều mẹo loại này đã lỗi thời từ Python 3.11 nhờ specializing interpreter. Chỉ áp dụng khi profiler chỉ rõ một vòng lặp nóng, và luôn đo lại.

Bài tập

1. Lấy một script bạn từng viết (xử lý file, crawl dữ liệu…), chạy python -m cProfile -s cumtime và tìm 3 hàm tốn thời gian nhất.
2. Viết hàm tìm các cặp số trong list có tổng bằng target bằng hai vòng lặp lồng nhau, sau đó tối ưu bằng set. Đo với list 10.000 phần tử.
3. Chạy một script tính toán lâu (ví dụ vòng lặp vô hạn tính số nguyên tố), dùng py-spy top và py-spy dump để quan sát nó từ terminal khác.

Kết luận

• Đo trước, tối ưu sau - trực giác về chỗ chậm thường sai.
• perf_counter cho đoạn dài, timeit cho đoạn ngắn; tránh các sai lầm khi đo.
• cProfile tìm hàm chậm (tottime, cumtime); py-spy quan sát chương trình đang chạy mà không cần sửa code.
• Cải thiện lớn nhất đến từ thuật toán và cấu trúc dữ liệu, tiếp theo là để C/NumPy làm vòng lặp.
• Sau mỗi thay đổi: kiểm tra kết quả vẫn đúng, rồi đo lại.

---

Đây là bài cuối của mục Python Nâng Cao. Nếu bạn đã đi hết các bài, bạn đã hiểu Python từ cách object nằm trong bộ nhớ, cách bytecode được thực thi, tới cách tận dụng mọi lõi CPU và đo đạc hiệu năng. Quay lại bài đầu tiên bất cứ khi nào cần ôn lại nền tảng.