跳过正文
  1. 文章/

缩容到零,于是每次重启都是一次 30 秒的故障

· loading · loading ·
仁才德
作者
仁才德
居住在韩国首尔的领导者和软件工程师

我本来只是去 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 Timeout2,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.438

44 到 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 文件:0

Django、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__/
*.pyc

Docker 是拿它们去匹配整条相对路径,而不是路径的每一段,所以没有锚定的模式只会在构建上下文的根目录生效。所有嵌套的 __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” 这一句,打开了整个下午。

我建议你在自己的应用里检查什么
#

如果你跑在任何会停掉空闲实例的平台上,下面这些问题我花了半天,本可以省下好几周的静默失败:

  1. 冷启动要多久? 不是容器跑起来要多久,而是到它能响应一个真实请求要多久。如果你没法用秒数直接回答,就在需要它之前先量出来。
  2. 你的 entrypoint 里,哪些按启动执行的事其实属于部署? 迁移、静态文件收集、缓存预热、索引构建。做一次都没问题,做九十二次都很贵。
  3. 有东西在缓存你的字节码吗? 只有 PYTHONDONTWRITEBYTECODE 而构建里没有 compileall,答案就是没有。
  4. 你能用挂起代替停止吗? 如果不能,是什么挡着?我这边是一个从未被碰过的 swap。
  5. 边缘看得见、源站看不见的错误存在吗? 把两边比一比。那个差值不是统计口径的怪癖,而是死在中间的请求,你的应用日志永远不会显示它们。

顺带一提,这段时间里健康检查一直是绿的。它总是绿的:健康检查跑在一台已经起来的机器上,它没法报告这台机器存在之前的那三十秒。