Tôi mở dashboard của Cloudflare để tìm hiểu một đợt traffic tăng đột biến, và phát hiện bên dưới nó là một chuyện tệ hơn nhiều: trong một ngày, 22% tổng số request mà ứng dụng của tôi phục vụ đã bị lỗi. Không có cảnh báo nào bắn ra. Health check nào cũng xanh. Log trông hoàn toàn bình thường, vì những request bị lỗi chưa bao giờ tới được ứng dụng.
Hóa ra thủ phạm lại là chính script khởi động container của tôi: nó làm những việc hoàn toàn hợp lý, chỉ có điều là vào đúng thời điểm tệ nhất.
Đợt traffic tăng vọt chỉ là cú đánh lạc hướng#
Ban đầu tôi chỉ định tìm hiểu một khung giờ nhận khoảng 4,900 request, trong khi trung vị chỉ là 121. Có bốn mươi hai visitor khác nhau, tức là 110 request cho mỗi visitor. Người thật thì không lướt web kiểu đó.
Đó là một con scanner: một con bot duy nhất lần lượt dò qua các subdomain do nó tự bịa ra, và hỏi từng cái xem có secret nào không:
api-stage-asia.marucommunity.com/.env.local
api-us-east-1-demo.marucommunity.com/.env
api-eu-uat.marucommunity.com/wp-config.php~
app-test-us-east-1.marucommunity.com/actuator/configprops
prod-api-use2.marucommunity.com/.env.local
relay.marucommunity.com/.env.productionKhoảng ba mươi hostname, đủ mọi biến thể .env bạn nghĩ ra được, thêm cả các endpoint actuator của Spring Boot trên một ứng dụng Django. Tất cả đều nhận 301 chuyển về host chính, và không có gì bị lộ ra ngoài. Nhàm chán, và thật sự vô hại.
Nhưng nhân tiện đang mở trang analytics, tôi thử nhóm số liệu của cùng ngày đó theo status code. Vấn đề thật nằm ở đây.
| Status | Số request trong 24h |
|---|---|
| Tổng | 11,350 |
| 504 Gateway Timeout | 2,474 |
Hai mươi hai phần trăm. Và số lỗi này không rải đều khắp trang, mà dồn vào đúng những chỗ đau nhất:
| Endpoint | Số lỗi 504 |
|---|---|
| số thông báo chưa đọc | 621 |
| danh sách thông báo | 614 |
| số tin nhắn chưa đọc | 469 |
| feed cursor | 210 |
Đây đều là những endpoint mà ứng dụng di động của tôi poll mỗi 30 giây. Nên đây không phải một con số tỉ lệ lỗi trừu tượng. Đó là điện thoại của từng người dùng, âm thầm không tải được badge tin chưa đọc, suốt cả ngày, và nhiều khả năng là đã như vậy mấy tuần liền.
Vì sao log vẫn trông bình thường#
Phản xạ đầu tiên của tôi là ứng dụng đã bị chậm đi. Nhưng không phải. Tôi lấy từ kho log ra các dòng log request của chính ứng dụng trong một khung giờ tệ nhất:
[2026-09-08 01:00:29] "GET /api/v1/notifications/unread_count/" 304 61.615
[2026-09-08 01:00:29] "GET /api/v1/notifications/" 304 63.568
[2026-09-08 01:00:59] "GET /api/v1/notifications/unread_count/" 304 58.742
[2026-09-08 01:00:59] "GET /api/v1/notifications/" 304 105.438Từ bốn mươi bốn đến một trăm mili giây, toàn bộ đều là 304. Origin chạy rất nhanh.
Đó là manh mối quan trọng, và đáng để đúc kết thành một quy tắc: nếu edge báo lỗi mà origin chưa từng nghe thấy, thì request đã chết trước khi tới nơi. Lúc đó, hãy thôi đọc log ứng dụng và bắt đầu nhìn vào những gì đứng trước nó.
Trong trường hợp của tôi, thứ đứng trước là proxy của Fly.io, và câu trả lời nằm ở cách các machine của tôi được lên lịch chạy.
Scale to zero là lời hứa về tiền, không phải về latency#
Cấu hình của tôi trông như thế này, và thoạt nhìn thì khá hợp lý:
[http_service]
auto_stop_machines = 'stop'
auto_start_machines = true
min_machines_running = 1Machine nào rảnh thì tự dừng. Có traffic thì tự bật lại. Dùng bao nhiêu trả bấy nhiêu. Với một ứng dụng nhỏ có traffic lúc lên lúc xuống thất thường, đây đúng là thứ bạn cần, và đó cũng là lý do tôi khai báo mười machine nhưng gần như lúc nào cũng chỉ có một cái đang chạy.
Cái giá bị giấu đi ở đây là latency. Khi một request tới một machine đang dừng, sẽ có người phải ngồi chờ machine đó boot. Nếu thời gian boot lâu hơn sức chờ của proxy, người đó sẽ nhận về lỗi 504.
Vậy machine của tôi mất bao lâu để boot? Tôi chưa từng đo. Nhưng kho log thì biết, vì script khởi động có in ra từng giai đoạn, và dòng log nào cũng kèm machine id:
WITH s AS (
SELECT fly.app.instance AS inst, timestamp,
CASE WHEN message ILIKE '%Starting Granian%' THEN 'begin'
WHEN message ILIKE '%Migrations complete%' THEN 'migrated'
WHEN message LIKE '%"GET /api/health/%' THEN 'serving' END AS phase
FROM logs('koreapost', '2026-09-08')
)
SELECT inst,
min(timestamp) FILTER (WHERE phase = 'begin') AS started,
min(timestamp) FILTER (WHERE phase = 'migrated') AS migrated,
min(timestamp) FILTER (WHERE phase = 'serving') AS first_serve
FROM s GROUP BY instKết quả rất nhất quán trên mọi machine:
| Giai đoạn | Thời gian |
|---|---|
| Từ lúc boot đến khi chạy xong migration | 10 đến 13 giây |
| Từ lúc xong migration đến request đầu tiên được phục vụ | 8 đến 19 giây |
| Tổng | 25 đến 33 giây |
Sau đó tôi đếm xem chuyện này xảy ra bao nhiêu lần:
SELECT count(*) AS starts, count(DISTINCT fly.app.instance) AS machines
FROM logs('koreapost', '2026-09-08')
WHERE message ILIKE '%Starting Granian%'
-- starts: 92, machines: 10Chín mươi hai lần cold start chỉ trong một ngày. Mỗi lần là một khoảng nửa phút, trong đó request nào được route tới machine đó cũng đều timeout. Đến đây thì con số hai mươi hai phần trăm hết còn bí ẩn.
Thủ phạm nằm ngay trong entrypoint của tôi#
Đây là những gì mọi machine đều phải chạy trước khi chịu trả lời request:
if [ "$1" = "granian-api" ]; then
echo "Running migrations..."
python manage.py migrate --noinput
echo "Running collectstatic in background..."
python manage.py collectstatic --noinput &
exec granian --interface wsgi koreapost_project.wsgi:application ...
fiHãy đọc lại đoạn này, lần này nhớ trong đầu con số “92 lần mỗi ngày”.
migrate là một lần boot Django trọn vẹn: import mọi model, kết nối tới Postgres, query bảng migrations, rồi kết luận là chẳng có gì phải làm. Trên shared CPU, mất mười giây chỉ để không làm gì cả. collectstatic là lần boot Django trọn vẹn thứ hai, sau đó còn tải static file lên object storage, tranh giành đúng cái core duy nhất mà web server đang cố khởi động trên đó. Granian là lần boot thứ ba.
Ba trình thông dịch Python, hai trong số đó làm lại những việc đã xong từ trước, và chuyện này lặp lại mỗi khi một machine thức dậy.
Tôi viết như vậy là có lý do chính đáng, và có lẽ entrypoint của bạn trông na ná cũng vì lý do đó: migration thì phải chạy ở đâu đó, release_command của Fly từng bị treo với tôi, và entrypoint là nơi duy nhất chắc chắn được chạy khi deploy. Đặt việc của deploy vào đó là đúng. Có điều, đó không phải chỗ đúng để chạy việc đó mỗi lần machine khởi động, và một khi machine tự dừng rồi tự bật lại, hai sự kiện này không còn là một nữa.
Toàn bộ bug chỉ có vậy, và tôi nghĩ nó khá phổ biến:
Những việc thuộc về một lần release lại bị chạy lại mỗi lần machine khởi động. Scale-to-zero biến một sự kiện thành chín mươi hai sự kiện.
Cách sửa: mỗi release chỉ chuẩn bị đúng một lần#
Migration không cần chạy lại trên machine thứ tám boot từ cùng một image. Nó chỉ cần chạy một lần cho image đó, và mọi machine khác cần biết là việc này đã xong.
Nói cách khác, ta cần một cái lock có tên thay đổi theo từng lần deploy. Fly cung cấp sẵn cái tên đó trong FLY_IMAGE_REF, còn Redis thì tôi đã có sẵn. Tất cả chỉ là một script nhỏ chạy trước khi Django được load, nên trong trường hợp thường gặp, nó chỉ tốn vài mili giây thay vì một lần boot cả framework:
def release_id() -> str:
"""Something that changes exactly when the deployed image does."""
return os.getenv("FLY_IMAGE_REF") or os.getenv("FLY_MACHINE_VERSION") or ""
def claim() -> int:
release = release_id()
if not release:
return PREPARE
client = _client()
if client is None: # no Redis: behave exactly as before
return PREPARE
done_key, lock_key = _keys(release)
if client.get(done_key): # somebody already did it for this image
return SKIP
owner = os.getenv("FLY_MACHINE_ID", "unknown")
if client.set(lock_key, owner, nx=True, ex=LOCK_TTL_SECONDS):
return PREPARE # we won the race; we do the work
# Someone else is preparing. Wait for them, because serving requests
# against a half-migrated schema is worse than starting slowly.
deadline = _monotonic() + WAIT_SECONDS
while _monotonic() < deadline:
_sleep(POLL_SECONDS)
if client.get(done_key):
return SKIP
if not client.get(lock_key) and client.set(lock_key, owner, nx=True, ex=LOCK_TTL_SECONDS):
return PREPARE # the owner died mid-migration; take over
return PREPARE # waited long enough; do it ourselvesEntrypoint giờ chỉ còn một câu if:
if python3 koreapost_project/release_gate.py claim; then
python manage.py migrate --noinput
python manage.py collectstatic --noinput &
python3 koreapost_project/release_gate.py done
fi
exec granian --interface wsgi koreapost_project.wsgi:application ...Mọi nhánh lỗi đều phải dẫn tới “cứ chuẩn bị đi”#
Phần đáng học theo nằm ở đây, hơn là ở đoạn mã.
Một cái gate như thế này đứng giữa người dùng và một lần migration schema. Nếu nó sai theo hướng bỏ qua, bạn sẽ phục vụ request trên một cơ sở dữ liệu chưa được migrate, và đó là một sự cố thật sự nghiêm trọng. Còn nếu nó sai theo hướng chuẩn bị, bạn chỉ chạy lại một migration idempotent vốn chẳng làm gì, và mất thêm mười giây.
Hai kết cục này không ngang nhau, nên mã nguồn không được xử lý chúng như nhau. Mọi nhánh không chắc chắn đều trả về PREPARE:
- Không có Redis, hoặc không kết nối được tới Redis. Chuẩn bị. Đây chính là hành vi cũ, nên nếu cache có sập thì hệ thống chỉ “chậm” chứ không “hỏng”.
- Biến môi trường không có image reference. Chuẩn bị. Không biết đây là release nào thì cũng không thể biết nó đã sẵn sàng hay chưa.
- Machine đang giữ lock chết giữa chừng lúc chạy migration. Lock của nó sẽ hết hạn, và machine tiếp theo đang chờ sẽ giành lấy lock rồi chuẩn bị.
- Chờ quá thời gian timeout. Cứ chuẩn bị. Một machine không bao giờ phục vụ được còn tệ hơn một lần migration bị chạy trùng.
Có một điểm bất đối xứng tôi cố ý đặt theo chiều ngược lại: machine nào thấy một machine khác đang giữ lock thì sẽ chờ chứ không phục vụ request. Khởi động chậm một chút trong lúc deploy thì không sao. Nhưng trả lời query trên một schema mới áp dụng được một nửa thì có sao đấy.
Nếu bạn dựng cơ chế này trên một wrapper cache kiểu “chịu lỗi” như tôi, hãy cẩn thận với một cái bẫy. Khi không kết nối được Redis, wrapper của tôi trả về False từ add(), trông y hệt kết quả “đã có machine khác giữ lock”, và nếu không để ý thì đã khiến mọi machine bỏ qua migration. Đó chính xác là hướng nguy hiểm. Hãy phân biệt hai trường hợp bằng cách đọc lại lock: nếu không ai giữ lock, nghĩa là cache đang hỏng, chứ không phải bạn thua cuộc đua.
Kiểm thử mà không cần Redis#
Logic này đáng để viết unit test, vì những nhánh đáng chú ý nhất lại chính là những nhánh bạn không thể tái hiện bằng tay. Chỉ cần một bản fake có hai method là đủ:
class FakeRedis:
"""Enough of redis-py for the gate: get, and set with nx/ex."""
def __init__(self) -> None:
self.store: dict[str, str] = {}
def get(self, key): return self.store.get(key)
def set(self, key, value, nx=False, ex=None):
if nx and key in self.store:
return None
self.store[key] = value
return TrueSau đó, dựng các trường hợp khó bằng cách tự điều khiển thời gian trôi. Lưu ý là gate gọi các alias _sleep và _monotonic ở cấp module chứ không gọi thẳng time.sleep, nên test có thể thay thế chúng mà không phải patch module time cho mọi thread khác trong process:
def test_a_waiter_takes_over_when_the_owner_disappears(self):
self.assertEqual(release_gate.claim(), release_gate.PREPARE) # owner takes the lock
_done, lock_key = release_gate._keys(release_gate.release_id())
def owner_dies(_seconds):
self.redis.store.pop(lock_key, None) # its lock expired
with patch.object(release_gate, "_sleep", owner_dies):
self.assertEqual(release_gate.claim(), release_gate.PREPARE)Có hiệu quả không? Được một phần#
Deploy, dừng một machine, bật lại, rồi canh đồng hồ. Giờ đây lúc khởi động, script báo ra quyết định của nó rồi nhường đường luôn:
15:23:34 Starting Granian (API server — HTTP/1.1 + HTTP/2)...
15:23:36 release gate: this release is already prepared, starting straight away
15:23:44 "GET /api/health/ HTTP/1.1" 200Mười giây, và một machine thứ hai đo được mười một giây. So với 25 đến 33 giây trước đó, hai phần ba khoảng thời gian chết đã biến mất, và bản thân cái gate chỉ tốn hai giây vì nó không bao giờ import Django.
Nhưng mười giây vẫn là mười giây. Request nào tới trong những giây đầu tiên đó vẫn bị lỗi. Nên tôi đi tìm tiếp phần còn lại.
Bytecode không ai cache#
Image có một dòng mà gần như Dockerfile Python nào cũng có:
ENV PYTHONDONTWRITEBYTECODE=1Đây là lời khuyên đúng. Container không nên tự ghi các tệp .pyc vào layer lúc runtime. Nhưng tôi chưa bao giờ nghĩ kỹ về nửa còn lại của vấn đề: nếu lúc runtime không ghi bytecode, lúc build cũng không ghi, thì chẳng có gì được cache cả, và mỗi lần process khởi động là compile lại toàn bộ cây dependency từ mã nguồn.
Tôi thử đếm:
site-packages .py files : 5,707
site-packages .pyc files : 0Django, DRF, mọi thư viện đều bị compile lại trong từng lần khởi động, 92 lần mỗi ngày. Đo trên một machine production:
django.setup() | Thời gian |
|---|---|
| Bản đang chạy hiện tại | 5.15s |
Sau khi chạy compileall | 3.17s |
Cách sửa chỉ có một dòng, và vì compileall luôn ghi bytecode ra tệp, nên nó vẫn hoạt động bất kể biến môi trường kia:
RUN python -m compileall -q /app/.venv/lib /app/koreapost_project /app/marketplace /app/utils || trueTốn thêm mười sáu giây lúc build, chỉ một lần, trong một layer được cache.
Nhân tiện, tôi còn phát hiện thêm một vấn đề âm thầm hơn. Tệp .dockerignore ghi:
__pycache__/
*.pycDocker so khớp các pattern này với toàn bộ đường dẫn tương đối, chứ không phải với từng thành phần của đường dẫn, nên một pattern không có neo sẽ chỉ khớp ở thư mục gốc của build context. Kết quả là mọi thư mục __pycache__ lồng bên trong đều bị đóng gói theo. Image chứa 218 tệp .pyc do Python 3.15 compile trên laptop, đi nhờ trong một image có trình thông dịch 3.14, và tất cả đều bị lặng lẽ bỏ qua. Pattern đúng phải là **/__pycache__/ và **/*.pyc.
Nói thật thì kết quả không như kỳ vọng: tính từ đầu đến cuối, cách này chỉ bớt được khoảng một giây chứ không phải hai. Mười giây còn chín. Benchmark đo riêng lẻ đã phóng đại, như benchmark đo riêng lẻ vẫn thường vậy.
Suspend, và dòng cấu hình đang chặn nó#
Đến mức chín giây thì tôi hết thứ để cắt bỏ. Phần còn lại là một lần boot không thể tránh: Python khởi động, Django import, rồi ứng dụng WSGI chạy lên trên một core dùng chung.
Vậy thì đừng boot nữa. Thay vì tắt hẳn machine, Fly có thể chụp snapshot bộ nhớ của nó:
[http_service]
auto_stop_machines = 'suspend' # was 'stop'Tôi thử bật lên thì Fly từ chối, kèm theo thông báo lỗi hữu ích nhất trong cả quá trình này:
failed to suspend VM: failed_precondition:
Machines with swap cannot be suspendedGần đầu tệp cấu hình của tôi có đoạn này, kèm một comment do chính tôi viết và tin sái cổ:
# Swap cushion so a memory spike swaps to disk instead of getting OOM-killed.
swap_size_mb = 2048Một biện pháp phòng ngừa hợp lý. Nhưng nó có thực sự làm gì không? Machine nào cũng báo:
MemTotal: 985220 kB
SwapTotal: 2097148 kB
SwapFree: 2097148 kBChưa từng có một page nào bị swap. Log trong ngày cũng không có vụ OOM kill nào — mười một dòng khớp với chữ “oom” hóa ra là request tới một bundle JavaScript mà content hash tình cờ chứa ba chữ cái đó. Trong khi đó, cơ chế bảo vệ bộ nhớ thật sự lại nằm ở một chỗ hoàn toàn khác, ngay trong lệnh chạy server: --workers-max-rss 800 sẽ khởi động lại worker từ lâu trước khi nó chạm tới trần 1GB.
Nói cách khác, cái đệm swap là bảo hiểm cho một sự cố chưa từng xảy ra, vốn đã có cơ chế khác lo, và phí bảo hiểm phải trả là mất khả năng suspend. Tôi bỏ nó đi.
| Cách đánh thức | Thời gian đến khi phục vụ được |
|---|---|
| Cold boot, sáng nay | 25 đến 33s |
| Cold boot, sau khi thêm gate và cache bytecode | 9 đến 10s |
| Resume từ suspend | 2.5 đến 3.1s |
Ba lần thử, các kết quả chênh nhau không quá nửa giây. Ngay sau khi thức dậy, endpoint nào cũng trả về 200 trong 250 đến 435 mili giây.
Socket sẽ ra sao khi machine đang ngủ#
Chẳng có gì tốt đẹp cả, mà cũng không có hook nào để xử lý. Fly đóng băng VM; process không nhận được signal nào và không kịp đóng thứ gì trước khi ngủ. Những kết nối nó đang giữ vẫn nằm nguyên trong bộ nhớ lúc thức dậy, trỏ tới những socket mà đầu bên kia đã bỏ đi từ mấy phút trước.
Bạn không xử lý chuyện này lúc machine đi ngủ, mà lúc nó thức dậy, và phần lớn là nhờ những quyết định đúng đã có từ trước:
- Kết nối database được mở theo từng request (
conn_max_age = 0), nên không có kết nối sống lâu nào để bị cũ. - Redis cache chỉ xuống cấp chứ không ném exception. Một wrapper bắt lỗi kết nối và trả về cache miss.
Tôi đã được tận mắt thấy cái thứ hai phát huy tác dụng. Một lần resume ghi ra đúng cái lỗi bạn đoán được:
redis.exceptions.ConnectionError: Error while reading from fly-...và request gặp lỗi đó vẫn trả về 200 sau 3.6 giây, vì cache chết thì chỉ khiến trang chậm đi chứ không thành trang lỗi. Những lần resume sau đó thì log sạch trơn.
Nếu cache client của bạn ném exception khi gặp kết nối chết, suspend sẽ biến mỗi lần thức dậy thành một tràng lỗi 500. Hãy kiểm tra chuyện đó trước khi bật cấu hình này, đừng đợi đến sau.
Lần kiểm thử đã đánh lừa tôi#
Lần đo suspend đầu tiên cho thấy tính năng này là một thảm họa: 502 sau 30 giây, hai lần liên tiếp.
Lúc đó tôi đã ghim request vào một machine cụ thể bằng header fly-force-instance-id. Header này rất tiện khi load test một instance, nhưng lại cực kỳ tệ cho trường hợp này. Ép vào một instance cụ thể sẽ bỏ qua phần logic của proxy vốn có nhiệm vụ đánh thức machine. Thật ra Fly đã nói rõ điều đó, nếu tôi chịu đọc nó như một câu trả lời thay vì một thông báo lỗi:
machine was recently stopped and is unavailable to service requestCon số đáng quan tâm phải đến từ đường đi mà traffic thật đi qua. Tôi bắn bốn mươi request đồng thời qua edge, vượt xa soft limit là 12, để proxy buộc phải scale out sang các machine đang suspend:
status codes: 40 × 200
slowest: 2.1sCó hai bài học, và bài thứ hai là bài đắt giá hơn. Hãy đo trên đường đi mà người dùng thật sự đi, chứ không phải đường đi tiện cho việc gắn công cụ đo. Và khi công cụ từ chối làm gì đó, hãy đọc kỹ lời từ chối: chính câu “Machines with swap cannot be suspended” đã gỡ nút thắt cho cả buổi chiều hôm đó.
Nếu là ứng dụng của bạn, tôi sẽ kiểm tra những gì#
Nếu bạn đang chạy bất cứ thứ gì trên một nền tảng tự dừng instance khi rảnh, thì những câu hỏi dưới đây chỉ tốn của tôi một buổi chiều, nhưng lẽ ra đã giúp tôi tránh được mấy tuần lỗi âm thầm:
- Một lần cold start mất bao lâu? Không phải container mất bao lâu để chạy, mà là mất bao lâu đến khi nó trả lời được một request thật. Nếu bạn không trả lời được câu này bằng một con số tính theo giây, hãy đo ngay, trước khi thật sự cần tới nó.
- Entrypoint của bạn đang làm những việc gì mỗi lần khởi động mà lẽ ra thuộc về deploy? Migration, gom static file, warm cache, build index. Làm một lần thì không sao. Làm chín mươi hai lần thì rất tốn kém.
- Có thứ gì đang cache bytecode cho bạn không? Nếu có
PYTHONDONTWRITEBYTECODEmà lúc build không chạycompileall, thì câu trả lời là không. - Bạn có thể suspend thay vì stop không? Nếu không, thì cái gì đang cản bạn? Với tôi, đó là một swap file chưa từng được dùng tới.
- Edge có thấy những lỗi mà origin không thấy không? Hãy so sánh hai bên. Khoảng chênh giữa chúng không phải do báo cáo bị lệch, mà là request đang chết ở khoảng giữa, và log ứng dụng sẽ không bao giờ cho bạn thấy điều đó.
À, nhân tiện, health check vẫn xanh suốt từ đầu đến cuối. Lúc nào chúng cũng xanh cả: health check chỉ chạy trên một machine đã khởi động xong. Nó không thể báo cáo gì về ba mươi giây trước khi machine đó tồn tại.

