为什么在 VyOS（Vyatta）中 commit 会很慢

最近就这个问题调查了蛮久，其实原因比较显然，在看到 strace 的结果就已经明白了大半，但是本着求(xia)知(zhe)探(teng)索的想法，仔细验证了代码逻辑和时间（新技能 get！给 C++、Perl 混合代码调试性能），攒出了这篇文章。

ZStack 是一个开源的 IaaS 软件，架构和性能都很优秀，可以在 103 秒内并发创建 1000 台虚拟机，可惜这个数据是在扁平网络下测试得到的，一旦用上云路由网络，单个虚拟机的启动时间会延长到七秒左右。

我们现看下看下实际的占用时间，我在 vyatta 的代码里添加了日志（Repo 是 https://github.com/vyos/vyatta-cfg ）综合 zstack、zstack-vyos、vyos 的日志可以看到大概是这样的（注意 zstack 的日志时间精度只提供到秒，没有毫秒）：

2017-02-13 13:22:08 start executing flow[NetworkServiceManagerImpl.java:apply-network-service-DHCP]

2017-02-13 13:22:08 DEBUG [RECV] /setsnat
2017-02-13 13:22:09 DEBUG [HTTP POST][ASYNC REPLY TO /setsnat]

2017-02-13 13:22:09 DEBUG [RECV] /adddhcp

# 以下为 vyos 日志
2017-02-13 13:22:09:458 Entered cli_bin::doCommit
2017-02-13 13:22:10:216 Entered commit::doCommit
2017-02-13 13:22:10:901 notify other users in config mode
2017-02-13 13:22:12:260 cs.commitConfig complete
2017-02-13 13:22:12:557 Exit commit::doCommit
2017-02-13 13:22:12:557 Normal exit cli_bin::doCommit
# 退出 vyos 日志

2017-02-13 13:22:12 DEBUG [HTTP POST][ASYNC REPLY TO /adddhcp]

2017-02-13 13:22:12 DEBUG [RESPONSE] to /setdns
2017-02-13 13:22:12 DEBUG [HTTP POST][ASYNC REPLY TO /setdns]

2017-02-13 13:22:12 DEBUG [SimpleFlowChain] (zs-thread-81) [FlowChain: apply-network-service-to-vm-13d1359b8bd34a05a91f61dedb112e96] successfully executed flow[NetworkServiceManagerImpl.java:apply-network-service-DHCP]

可以把时间与调用关系结合起来做成一张图：

可以看到很显然 cs.commitConfig 占用了很多时间，这个图是根据我的实验环境只有一个虚拟机启动的日志生成的，如果已经现存有多个虚拟机，可以发现 cs.commitConfig 占用的时间会不断增长。大概占整体时间的 58% 以上。

commit 时间很长的原因主要在于 vyos-cfg 的设计原因，vyos-cfg 通过 tmpfs 和 unionfs 来完成配置管理，换句话说，整个 configuration 是通过目录和文件保存在文件系统的：

而且由于通过 unionfs 来完成配置的合并，还用了大量临时目录（多个用户同时编辑的话需要大量复制临时目录，检查配置也需要临时目录），带来大量的 copy、stat 等 IO 操作，通过 hook cli_bin 并用 strace 跟踪显示，一次 commit 操作会带来大概五万个系统调用，其中4.87万都是文件相关的调用：