我本来只是去 Cloudflare 面板上看一个流量尖峰,结果在它下面发现了严重得多的东西:一天之内,应用处理的请求有 22% 是失败的。没有任何告警触发,健康检查全是绿的,日志看起来也完全正常。因为那些失败的请求,根本没有到达应用。
原因是我自己写的容器启动脚本,在完全错误的时机做着完全合理的事。
尖峰是个幌子#
我最初想解释的是这样一个小时:约 4,900 个请求,而中位数是每小时 121 个。独立访客 42 个。也就是每人 110 个请求,人类不是这么浏览网页的。
是扫描器。一个机器人在编造子域名,挨个向它们索要密钥文件:
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.production三十来个主机名,你能想到的每一种 .env 变体,外加冲着 Django 应用要的 Spring Boot actuator 端点。它们全部拿到了指向规范主机的 301,什么也没被返回。乏味,而且确实无害。
不过既然分析页面开着,我顺手把同一天按状态码分组了。真正的问题在那里。
| 状态码 | 24 小时请求数 |
|---|---|
| 总计 | 11,350 |
| 504 Gateway Timeout | 2,474 |
22%。而且不是均匀散布在整个站点,而是精确地压在最疼的地方:
| 端点 | 504 |
|---|---|
| 通知未读数 | 621 |
| 通知列表 | 614 |
| 消息未读数 | 469 |
| 信息流游标 | 210 |
这些都是移动端每 30 秒轮询一次的端点。所以这不是一个抽象的错误率数字,而是用户的手机整天、大概持续了好几周,都在悄悄加载不出未读角标。
日志为什么看起来正常#
我的第一反应是应用变慢了。并没有。我从日志归档里翻出最糟糕那个小时里应用自己的请求日志:
[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.43844 到 105 毫秒,清一色 304。源站很快。
这是关键线索,值得写成一条规则:如果边缘报告的错误是源站从没听说过的,那么请求是在到达之前就死掉了。 别再读应用日志,去看它前面的那一层。
在我这里就是 Fly.io 的代理,答案藏在机器的调度方式里。
缩容到零是关于成本的承诺,不是关于延迟的#
我的配置是这样,乍看之下相当合理:
[http_service]
auto_stop_machines = 'stop'
auto_start_machines = true
min_machines_running = 1空闲的机器停掉,来流量再启动,用多少付多少。对于流量有峰谷的小应用,这正是你想要的,也正因如此我定义了十台机器,平时却只有一台在跑。
它藏起来的账单是延迟。当一个请求打到一台已停止的机器上,总得有人等它启动完。如果启动比代理的耐心更久,这个人就会拿到 504。
那么我的机器启动要多久?我从来没量过。日志归档知道,因为启动脚本会打印每个阶段,而且每一行都带着机器 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 inst在每一台机器上,答案都一致:
| 阶段 | 耗时 |
|---|---|
| 启动到迁移完成 | 10 到 13 秒 |
| 迁移到处理第一个请求 | 8 到 19 秒 |
| 合计 | 25 到 33 秒 |
然后我数了数这件事发生的频率:
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: 10一天 92 次冷启动。每一次都打开一个半分钟的窗口,任何被路由到那台机器的请求都会超时。22% 不再神秘了。
原因就在我自己的 entrypoint 里#
这是每一台机器在响应任何请求之前都要跑的东西:
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 ...
fi带着「一天 92 次」再读一遍。
migrate 是一次完整的 Django 启动:导入所有模型、连上 Postgres、查询迁移表,然后判定无事可做。在共享 CPU 上,为了什么也不做花掉十秒。collectstatic 是第二次完整的 Django 启动,之后还要把静态文件上传到对象存储,同时和正在启动的 Web 服务器抢同一个核心。Granian 是第三次启动。
三个 Python 解释器,其中两个在重复已经做过的事,机器每醒来一次就来一遍。
当初这么写的理由是站得住脚的,你的代码大概也长得差不多:迁移总得在某处执行,Fly 的 release_command 曾经卡住过,而 entrypoint 是唯一保证会在部署时执行的地方。把部署工作放在这里是对的,只是把它放在每次机器启动时不对。而一旦你的机器开始自己停自己起,这两件事就不再是同一个事件了。
整个 bug 就是这一句,我认为它相当常见:
属于发布的工作,被按机器启动执行了。缩容到零把一个事件变成了九十二个。
解法:把发布只认领一次#
某个镜像的第八台机器不需要跑迁移。这个镜像只需要跑一次,其他机器只需要知道已经跑过了。
这就是一把每次部署都换名字的锁。Fly 用 FLY_IMAGE_REF 白送了这个名字,而 Redis 我本来就有。整个东西是一个在 Django 存在之前就运行的小脚本,所以常见情况下的答案是毫秒级,而不是一次框架启动:
def release_id() -> str:
"""恰好在部署镜像变化时才变化的值。"""
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: # 没有 Redis:行为和以前完全一致
return PREPARE
done_key, lock_key = _keys(release)
if client.get(done_key): # 这个镜像已经有人准备好了
return SKIP
owner = os.getenv("FLY_MACHINE_ID", "unknown")
if client.set(lock_key, owner, nx=True, ex=LOCK_TTL_SECONDS):
return PREPARE # 抢到了,由我们来做
# 有别人在准备,那就等。对着迁移了一半的库提供服务,
# 比启动慢一点要糟糕得多。
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 # 持有者在迁移途中挂了,接管过来
return PREPARE # 等够久了,自己动手entrypoint 变成一个 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 ...每一种失败都必须落在「那就准备」上#
比起代码,这一节更值得抄走。
这样一个门闩,站在你的用户和一次库迁移之间。如果它朝跳过的方向出错,你就会对着一个没迁移的数据库提供服务,那是真正的故障。如果它朝准备的方向出错,你只是把一次幂等的空迁移跑了两遍,浪费十秒。
这两个结果并不对称,所以代码也不能对称地对待它们。每一条不确定的路径都返回 PREPARE:
- 没有 Redis,或者 Redis 不可达。 准备。这正是旧行为,于是缓存故障退化成「慢」,而不是「坏」。
- 环境里没有镜像引用。 准备。我不知道这是哪个发布,也就无从知道它是否就绪。
- 锁的持有者在迁移途中死了。 它的锁过期,下一个等待者接管并准备。
- 等待超过了超时时间。 还是准备。一台永远不提供服务的机器,比一次重复迁移更糟。
反方向上我故意留了一处不对称:发现另一台机器确实握着锁的机器会等待,而不是开始服务。部署期间启动慢一点没关系,对着只应用了一半的 schema 接受查询则不行。
如果你和我一样用带容错的缓存包装器来实现,有一个陷阱。我的包装器在 Redis 不可达时让 add() 返回 False,而这读起来和「别人正持有锁」一模一样,那会让每台机器都跳过迁移——恰好是危险的那个方向。用回读锁来区分:一把没有任何人持有的锁,意味着缓存坏了,而不是你输掉了竞争。
不用 Redis 也能测#
这段逻辑值得写单元测试,因为真正有意思的路径恰恰是你没法手工复现的。一个两方法的假对象就够了:
class FakeRedis:
"""够门闩用的 redis-py:get,以及接受 nx/ex 的 set。"""
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 True然后按自己的节奏推动时间,去跑那些别扭的分支。注意门闩调用的是模块级的 _sleep 和 _monotonic 别名,而不是直接调用 time.sleep,这样测试替换它们时不会波及同进程里的其他线程:
def test_a_waiter_takes_over_when_the_owner_disappears(self):
self.assertEqual(release_gate.claim(), release_gate.PREPARE) # 持有者拿到锁
_done, lock_key = release_gate._keys(release_gate.release_id())
def owner_dies(_seconds):
self.redis.store.pop(lock_key, None) # 它的锁过期了
with patch.object(release_gate, "_sleep", owner_dies):
self.assertEqual(release_gate.claim(), release_gate.PREPARE)有效果吗,一半#
部署之后,停掉一台机器再启动,同时看着表。现在启动过程会说出自己的判断,然后立刻让路:
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" 200十秒,第二台量到十一秒。对比之前的 25 到 33 秒,这个窗口消失了三分之二,而门闩本身只花两秒,因为它从不导入 Django。
但十秒还是十秒。落在这十秒最开头的请求依然会失败。于是我去找剩下的部分。
没有人在缓存字节码#
镜像里有一行,几乎每一个 Python Dockerfile 都写着它:
ENV PYTHONDONTWRITEBYTECODE=1这是好建议。容器不该在运行时把 .pyc 涂进镜像层里。我没有想透的是这笔交易的另一半:如果运行时从不写字节码,而构建时也不写,那就没有任何东西被缓存,于是每一次进程启动都要把整棵依赖树从源码编译一遍。
我数了数:
site-packages .py 文件:5,707
site-packages .pyc 文件:0Django、DRF、每一个库,在那 92 次日常启动里每次都重新编译。在生产机器上实测:
django.setup() | 耗时 |
|---|---|
| 出厂状态 | 5.15 秒 |
compileall 之后 | 3.17 秒 |
修复是一行,而且 compileall 是显式写入,所以那个环境变量拦不住它:
RUN python -m compileall -q /app/.venv/lib /app/koreapost_project /app/marketplace /app/utils || true十六秒的构建时间,只此一次,还在一个可缓存的层里。
顺手还发现了一个更安静的问题。.dockerignore 里写着:
__pycache__/
*.pycDocker 是拿它们去匹配整条相对路径,而不是路径的每一段,所以没有锚定的模式只会在构建上下文的根目录生效。所有嵌套的 __pycache__ 都被打进了镜像。里面有 218 个由笔记本上的 Python 3.15 编译出来的 .pyc,躺在一个解释器是 3.14 的镜像里,被安静地全部忽略。正确的写法是 **/__pycache__/ 和 **/*.pyc。
诚实的结果:端到端只换来大约一秒,而不是两秒。十秒变成九秒。孤立的基准测试总是这样高估自己。
挂起,以及挡住它的那一行#
到了九秒,我已经没有可以再删的工作了。剩下的是一次无法避免的启动:Python 起来、Django 导入、WSGI 应用在一个共享核心上立起来。
那就别启动。Fly 可以给机器的内存做快照,而不是把它关掉:
[http_service]
auto_stop_machines = 'suspend' # 原本是 'stop'我去测试,Fly 拒绝了我,并给出了整件事里最有用的一条错误信息:
failed to suspend VM: failed_precondition:
Machines with swap cannot be suspended我的配置顶部有这么一段,注释是我自己写的,我也一直相信它:
# 一层缓冲,让内存尖峰换页到磁盘,而不是被 OOM 杀掉。
swap_size_mb = 2048听起来是合理的预防。它真的在干活吗?每一台机器的回答都是:
MemTotal: 985220 kB
SwapTotal: 2097148 kB
SwapFree: 2097148 kB一页都没有换出过。当天的日志里也没有 OOM kill——那 11 行匹配到 “oom” 的记录,是对一个内容哈希里恰好含有这三个字母的 JavaScript 包的请求。而真正的内存护栏在完全不同的地方,在服务器启动命令里:--workers-max-rss 800,远在触到 1GB 天花板之前就把 worker 重启了。
所以这层缓冲是一份针对从未发生过的事件的保险,而且已经被另一套机制覆盖,它的保费是挂起能力。删掉。
| 唤醒路径 | 到能响应 |
|---|---|
| 今天早上的冷启动 | 25 到 33 秒 |
| 加了门闩和字节码之后的冷启动 | 9 到 10 秒 |
| 从挂起恢复 | 2.5 到 3.1 秒 |
测了三次,波动不超过半秒。唤醒之后每个端点都在 250 到 435 毫秒内返回 200。
机器睡着时,你的套接字会怎样#
不会有好事,而且没有钩子可以补救。Fly 冻结整个虚拟机:进程收不到信号,下坠途中什么也关不掉。它握着的连接在醒来时仍然留在内存里,指向对端几分钟前就已经丢弃的套接字。
这个问题不在下去的时候解,而在上来的时候解,而且多半取决于你之前是否已经做对了选择:
- 数据库连接按请求打开(
conn_max_age = 0),没有活得够久、够得着变质的连接。 - Redis 缓存是降级而不是抛异常。 包装器捕获连接错误并返回一次未命中。
我亲眼看到第二条挣到了它的位置。某次恢复时,日志里出现了完全在预料之中的失败:
redis.exceptions.ConnectionError: Error while reading from fly-...而它所在的那个请求,用 3.6 秒返回了 200——死掉的缓存意味着慢一点的页面,而不是错误页面。之后的恢复什么都没记。
如果你的缓存客户端在连接死掉时会抛异常,挂起就会把每一次唤醒变成一串 500。在打开这个开关之前确认,而不是之后。
那个骗了我的测试#
我第一次测挂起,结论是这功能糟透了:502,30 秒之后,而且连着两次。
我用 fly-force-instance-id 把请求钉在了某一台机器上。用来压测单个实例时这是个好头部,用在这里则糟糕透顶:强制指定实例会绕过本该把它唤醒的代理逻辑。Fly 其实早就告诉我了,只要我把它当成答案而不是错误来读:
machine was recently stopped and is unavailable to service request有意义的数字来自真实流量走的那条路。经由边缘发出 40 个并发请求,远超 12 的软上限,逼得代理必须扩容到挂起的机器上:
状态码: 40 × 200
最慢的一个:2.1 秒两个教训,贵的是第二个。去测量用户走的那条路,而不是方便插桩的那条路。以及,当你的工具拒绝你的时候,去读那句拒绝——“Machines with swap cannot be suspended” 这一句,打开了整个下午。
我建议你在自己的应用里检查什么#
如果你跑在任何会停掉空闲实例的平台上,下面这些问题我花了半天,本可以省下好几周的静默失败:
- 冷启动要多久? 不是容器跑起来要多久,而是到它能响应一个真实请求要多久。如果你没法用秒数直接回答,就在需要它之前先量出来。
- 你的 entrypoint 里,哪些按启动执行的事其实属于部署? 迁移、静态文件收集、缓存预热、索引构建。做一次都没问题,做九十二次都很贵。
- 有东西在缓存你的字节码吗? 只有
PYTHONDONTWRITEBYTECODE而构建里没有compileall,答案就是没有。 - 你能用挂起代替停止吗? 如果不能,是什么挡着?我这边是一个从未被碰过的 swap。
- 边缘看得见、源站看不见的错误存在吗? 把两边比一比。那个差值不是统计口径的怪癖,而是死在中间的请求,你的应用日志永远不会显示它们。
顺带一提,这段时间里健康检查一直是绿的。它总是绿的:健康检查跑在一台已经起来的机器上,它没法报告这台机器存在之前的那三十秒。

