跳到主要内容
仪表盘说这次成了,可日志里第 1 步躺了四遍

仪表盘说这次成了,可日志里第 1 步躺了四遍

今天也没搞懂
今天也没搞懂

· 阅读约 6 分钟

学 Temporal 的第三周。

昨晚干的事说出来有点变态:写个工作流,10 个 activity 串着跑,每个先往文件里追加一行执行记录,再 sleep 3 秒,假装自己在调支付。

然后就守着它。随机时刻 kill -9 掉 worker,杀了 8 次,每次杀完立刻起一个新的。

不打断的话这玩意儿 30 秒左右跑完。八次强杀之后 69.2 秒,completed,返回值也对,10 个步骤的输出按顺序一个不多一个不少。

看到这儿我本来打算写一篇「Temporal 真牛」的日记。

顺手 cat 了一下那个副作用文件。

step-01 executed
step-01 executed
step-01 executed
step-01 executed
step-02 executed
...
step-10 executed

第 1 步四次。第 2 到第 10 步各一次。

第一反应是文件写重复了吧?又回头看仪表盘——仪表盘上这次运行是绿的,一次成功。绿的。文件里那一行躺了四遍。

这是为什么啊?

「工作流恰好一次、activity 至少一次」这句话我早就读到过,当时觉得自己懂了。现在才明白我懂的是字面,不是这里。字面懂了跟真碰上,完全是两码事。


第一次 kill 撞在第 1 步跑到 2.9 秒的时候。新 worker 几秒就起来了,但接下来大概 8 秒,什么都没发生。

不是它反应慢。是它压根没有「反应」这个动作。Server 不知道我那个 worker 已经死了,它只能等 start_to_close_timeout 到期,我设的 10 秒。

第 1 步四次尝试的开始时间大概在 0.3 秒、11.3 秒、23.3 秒、37.3 秒。间隔是 10 秒超时加退避的 1 秒、2 秒、4 秒。

事件历史里还有个东西我一开始没看懂:10 个步骤,只有 10 个 ActivityTaskStarted。第 1 步那个事件上写着 attempt=4,最后一次失败原因是 StartToClose timeout。前三次失败没有各自留一条事件,全被折进最后那次成功的尝试计数里了。历史看上去像「它只启动过一次」,其实启动了四次,只是折叠了。折叠这个词是我自己瞎叫的,也不知道准不准,但它确实是那个感觉——四次尝试压成一个数字,只有点进那一行才看得见。

八次 kill 里只有 3 次真打断了第 1 步,另外 5 次全落在空闲 worker 上,白杀。算出来那一刻有点不服气,我自认为设计得挺"随机"的计划,一半打在了空气上。


然后是这段里最打我脸的地方。

我加心跳,每 0.5 秒一次、超时 2 秒,想着检测快了,重复总该少点吧?2.9 秒那次 kill,这次 4.9 秒就重试了,快是真快。

重复次数反而更多。仅超时模式四组 kill 计划下是 3、3、2、2;加了心跳变成 6、4、5、5。中位完成时间还从 66.5 秒爬到 70.7 秒。

我盯着这组数字看了挺久,心里那句「那我加它干嘛」都冒出来了。

后来大概想明白了:检测快了,意味着进程死的那一刻正在跑的任务更容易被判失败重跑;而失败后的指数退避又把我省下来的时间吃回去。两头一抵,净亏。

但我不打算把心跳删掉。真实环境里 worker 崩一次是稀罕事,把故障检测从 10 秒压到 2 秒,这个收益本身是真的。我这个小实验是拿 kill 当饭吃,八次强杀全砸在一分钟里,比例严重失真。这条我先留着,但我也不敢说别人照抄就合适。


重复本身消不掉,那就只能让它重复了也不出事。

我用 workflow_id 拼 activity_id 当幂等键,往一张带唯一约束的 SQLite 表里插,插不进去就当重复。最狠的那次心跳模式重跑,日志里 15 次 activity 执行,扣款只有 10 次。第 1 步执行 6 次,扣款 1 次。

这个「1 次」看着很爽,但我知道它在真实支付场景里不够——本地去重表只能挡住我这边,钱已经在对方那边走过了。真接支付,得把同一个幂等键塞进对方的幂等请求头里,光维护本地那张表没用。这句写在这儿是提醒以后的自己,我还没真接过,不敢当成经验讲。


回放测试是我另一个卡了很久的地方。

第一次跑,包括那个什么都没改的对照组在内,所有用例全被判拒绝。一个连对照组都过不了的东西,按理说我该先怀疑测试本身,但当时我怀疑的是 Temporal 不让我回放。查了半天,原因是我把 workflow 定义和 asyncio.run(main()) 放在同一个模块里,沙箱重新导入模块的时候把测试又跑了一遍。

分两个文件之后就好了。

拆完之后看清楚:拿那份八次 kill 留下的 65 事件历史去回放,插入一个新 activity 被拒,把循环从 10 步改成 9 步被拒,报 TMPRL1100,说调度事件里的 activity 类型和命令里的类型对不上。

但是把 10 个步骤顺序整个反转——过了。给每一步传完全不同的参数——也过了。把超时从 10 秒改成 999 秒——照样过。

所以它比的是形状,活动的类型和顺序,不比参数。这个我认,道理上也说得通。

但紧接着我自己后背一凉:Temporal 分给 activity 的 ID 是 1 到 10,跟步骤位置绑死的。顺序反转之后,第一个 activity 按位置还是匹配原来第一个,所以回放过;可它在业务上已经是另一步了。如果新版本重排了步骤,还继续拿位置拼幂等键,那个键就落到别的步骤头上。

这个后果我没测。我不知道它会怎么坏,只知道真坏了大概很难查。先记这儿。


还有个纯手滑的:我用 pkill -f 停开发服务器,模式写宽了,把自己 shell 也一起杀了,后来改成 [t]emporal 才躲开自己。

以及最开始我想在 workflow 代码里读环境变量当超时,Python SDK 沙箱运行时直接甩 RestrictedWorkflowAccessError,后来改成把超时当工作流参数传进去。


写到这儿,这篇其实没有「我搞定了」的东西。

工作流确实没丢进度、没坏状态,八次强杀之后结果还是对的——但这跟我一开始以为的那个「稳」,不是一回事。

我现在的理解就一句:工作流可以恰好完成一次,但里面每个 activity 都得按至少跑一次来设计,副作用必须有幂等键。回放通过只能说明它形状没变,不能说明它还干着原来那件事。

这个理解是不是还挺夹生?大概率是。

评论区蹲一个大佬:位置型 ID 配幂等键这个坑,有没有人真踩过,坏起来是什么样?