最新已推送状态:详细耗时 profile
提交与结论
本轮先完成并推送三个提交到 origin/main:
0548efe:完整负载历史矩阵、资源回归归因工具与报告。b5d16b4:独立提交已有的 SSG 宿主额度政策。214de5fec5ea796a047024510566168e1fa81d08:按轮固定输入、移除版本扫描和批次失效契约。
下面全部测量固定最后这个提交,普通二进制从 git archive 的源码重新构建,不改 CLI 额度,不复用之前的计时样本。profile 之后没有修改生产代码、消费者或依赖锁。
主要结论:
完整 XIV 的成本分散在发布、生成准备和文档分析,分别占阶段探针内总耗时约 24.1%、22.7%、18.8%;逐页模板占 13.2%。只优化模块编译或 HTML Renderer 无法解决它的大头。
其余四个完整站点都以求值为第一热点,占 52.6%–71.5%;无模块正文也有 62.1% 在求值。这已不是旧的文件版本扫描问题。
comemo 实际在工作:共享图实际编译 18 个模块,宽导出图 6 个;宽导出实际绑定只有 11 次。不能把它的 1.50 s 主要归因于“反复编译 256 个导出”。私有图仍实际编译 5,120 个模块,约 133 ms。
文件发布不只是写文件:XIV 的写出约 425 ms,清理旧目录约 357 ms。站点普通对象析构远小于旧目录删除,二者不能混为同一种“收尾”。
求值中的重复树拷贝值得优先处理,而不是继续删除预算检查:宽导出补充探针中,被单独计时的 clone 位置合计约 488 ms;结构检查约 4.46 ms,内容计数约 3.93 ms。补充探针自身增加约 9.2% 耗时,这些数值只作独立归因,不冒充普通二进制的耗时。
五个主负载均没有语言 Data API 调用;SSG 的 site.data 序列化约 95 ms 是另一个宿主阶段。JSON/TOML 正向控制确认读取、解析与命中探针都连通。
普通 release:完整 CLI 实测
五轮新进程,固定 CPU 8,先完整预热文件系统;CPU 为环境报告的 AMD Ryzen 9 9950X3D2,governor=powersave,未锁频。user/system 为五轮均值,包含 CLI 等待并回收的子进程 CPU 用量,不是某个 Rust 函数的 CPU 时间。
完整负载 | HTML 页数 | wall 中位数 s | wall 范围 s | user 均值 s | system 均值 s |
|---|---|---|---|---|---|
完整 XIV DB | 51,739 | 3.4183 | 3.3685–3.4408 | 2.4222 | 0.9256 |
无模块正文 | 521 | 0.4702 | 0.4651–0.4753 | 0.4373 | 0.0269 |
共享组件图 | 521 | 0.8130 | 0.7976–0.8209 | 0.7587 | 0.0403 |
每页私有模块图 | 521 | 1.0552 | 1.0306–1.0579 | 0.9647 | 0.0689 |
宽导出/通配绑定 | 521 | 1.4959 | 1.4668–1.5022 | 1.4171 | 0.0520 |
完整保留 XIV 的真实 CSV、全部页面及正文;另四种仍为 512 详情+8 目录+首页。计时包括启动、扩展、分析、求值、HTML、模板、事务发布与退出;编译、预热和输出校验在计时外。
阶段归因:互不重叠的分区
以下来自独立 coarse 探针三轮的均值,单位 ms。每列分项加总为该探针内的 cli.total;不将普通 wall 中位数按这些比例硬拆,也不把父子 Inclusive 相加。exec/动态加载等 main 之前的时间不在 cli.total 内。
阶段 | XIV | 无模块 | 共享图 | 私有图 | 宽导出 |
|---|---|---|---|---|---|
发现、初始读取、扩展与源目录 | 771.604 | 6.087 | 5.733 | 5.669 | 5.854 |
文档分析 | 640.058 | 130.994 | 203.658 | 416.541 | 317.379 |
求值 | 102.409 | 289.273 | 541.199 | 546.478 | 1,056.518 |
路由与管线其他装配 | 118.041 | 7.838 | 12.554 | 12.229 | 16.773 |
资源与模板加载 | 0.699 | 0.170 | 0.196 | 0.198 | 0.228 |
正文 HTML、链接与组件 | 168.715 | 10.526 | 14.059 | 17.093 | 26.015 |
共享模板上下文 | 176.825 | 0.335 | 0.399 | 0.379 | 0.521 |
逐页模板与产物登记 | 449.365 | 1.330 | 1.432 | 1.414 | 1.486 |
站点局部数据析构 | 99.919 | 10.324 | 19.120 | 21.973 | 38.411 |
事务发布 | 820.550 | 7.395 | 7.412 | 9.891 | 8.706 |
宿主与其余收尾 | 58.182 | 1.199 | 3.289 | 6.281 | 5.476 |
探针内 CLI 总计 | 3,406.368 | 465.470 | 809.051 | 1,038.147 | 1,477.365 |
SSG 总耗时减去显式阶段得到“站点局部数据析构”;宿主项包括 target 准备、Vault 回收及 CLI 其余工作。显式细分析构探针用于核对这个边界,不把它与旧输出目录清理相加重复计费。
XIV:进一步下钻
下列为独立 detail 探针三轮均值,和上节 coarse 表不是同一次计时。除特别注明的父项外,这些行对应不同范围;包含关系须按下面的说明理解。
范围 | 次数 | 时间 ms | 解释 |
|---|---|---|---|
stdio.process | 1 | 511.268 | Python 扩展、管道传输、等待及回收;不是纯 Python CPU |
stdio.decode | 1 | 120.257 | Rust 解码扩展 JSON 响应 |
stdio.encode | 1 | 0.007 | 编码扩展请求,很小 |
逐页模板 render | 51,739 | 274.398 | Tera 渲染正文/页面 |
模板输出登记 | 51,739 | 127.634 | 路径碰撞检查、字节产物登记等 |
逐页模板上下文 | 51,739 | 36.361 | 当前 page/directory/assets 绑定;其余细节见原始指标 |
原生 Markup parse | 51,739 | 214.325 | 生成页面仍经过真实前端 |
原生 Markup lower | 51,739 | 53.446 | 不含 parse |
ensure_environment Self | 51,739 | 144.814 | 环境缓存查找/插入、文本与环境句柄等自身工作 |
Environment.document | 51,739 | 81.790 | 父项,包含配置解析、输入查询和空导入绑定等 |
首次登记文档文本 | 51,739 | 68.466 | 批次资源登记,不是磁盘读取 |
environment_snapshot | 103,478 | 94.171 | 求值和 HTML 绑定查询已有环境 |
共享 page 值构造 | 1 | 51.421 | 一次构造全站页面值 |
共享 site.data 值构造 | 1 | 94.773 | serde 数据转成 Tera 共享值,非语言 read_json |
丢弃原始 site.data JSON | 1 | 25.886 | 已转成模板值后的原始树回收 |
丢弃模板共享值 | 1 | 57.058 | 成功返回边界的局部对象回收 |
丢弃文档树 | 1 | 39.990 | 不含 Vault 自己保存的输入/环境 |
丢弃 Vault | 1 | 35.537 | 宿主边界的输入与环境回收 |
发布写出 | 1 | 424.766 | 暂存目录建父目录、打开、写出并关闭文件 |
删除退休发布目录 | 1 | 356.911 | 目录替换后清理旧站点 |
ensure_environment 的 295.071 ms Inclusive = 自身 144.814 + Environment.document 81.790 + 文本登记 68.466 ms;这三项不能再与父项重复相加。配置解析自身只有 23.992 ms,不能把整个环境阶段都归因于 TOML。
此 XIV 消费者在 scripts/items.py 的 add_document 中生成属性文档,正文主要由 item/catalog 模板读取 site.data 生成。因此它没有 notc 模块编译,Resolve/Materialize 和求值树都很小;这不是删除了页面正文,也不能代表模块富集站点。
扩展 prepare 总计约 761 ms,其中 stdio 总计约 635 ms;余下约 126 ms 在扩展应用、候选输入处理和路径/路由验证等宿主工作。crates/notist-ssg/src/extensions.rs 目前在每个扩展之后及 prepare 结束时验证,随后 build 再建 Route;这是可继续调查的重复工作候选,本轮没有把这 126 ms 全部武断归因于某一处验证。
Python cProfile:独立完整运行
通过 PATH wrapper 用同一个 Python 解释器对原封不动的 scripts/items.py 开启 cProfile。该次 Python 总计 757.777 ms、1,713,026 次调用,包含插桩开销;对应 stdio.process 增至 801.647 ms,不替代普通扩展约 513 ms 的耗时。
函数/范围 | 次数 | Self ms | Inclusive ms |
|---|---|---|---|
parse_items | 1 | 265.863 | 318.147 |
json.dumps,所有调用合计 | 155,215 | 91.086 | 223.529 |
最终响应 iterencode | 1 | 71.954 | 71.954 |
属性生成器 | 206,952 | 49.903 | 201.464 |
extend | 1 | 42.732 | 630.071 |
add_document | 51,738 | 26.129 | 257.567 |
write_response | 1 | 0.007 | 88.714 |
生成页面的 title/template/id 等属性分别执行 JSON 字符串编码,所以批量编码最终响应之后仍有 155,214 次小字符串编码,再加一次最终响应 dumps。这是读取/转换完整 CSV、构造数据与生成页面元信息的真实成本,不是 Rust Data 解析开销。表中 json.dumps、属性生成器、add_document、extend 有包含关系,不相加。
系统调用旁证:完整输入,不用小站代替
strace 为独立运行,trace 秒数不参与性能排名,统计包含扩展子进程。
选定 syscall | 完整 XIV | 完整私有模块图 |
|---|---|---|
openat2 | 1 | 5,641 |
openat | 52,103 | 570 |
read | 843 | 27,763 |
write | 51,748 | 526 |
unlinkat | 51,751 | 529 |
mkdir | 51,749 | 527 |
statx | 52,219 | 17,736 |
rename | 2 | 2 |
XIV 的约五万次 write 与 unlinkat 同时存在,支持“写新站点+删除旧站点”解释;并非五万页导致五万次源模块读取。约五万次 mkdir 也与逐文件 create_dir_all 的实现相符,多数返回已有目录一类的探测失败,不能当作构建失败率;本轮全部成功构建退出码为零,未逐条统计 errno。
模块站:已从版本扫描转向真实求值
完整负载 | 分析 ms | 求值 ms | 求值占粗探针内总时间 |
|---|---|---|---|
无模块正文 | 130.994 | 289.273 | 62.1% |
共享组件图 | 203.658 | 541.199 | 66.9% |
每页私有模块图 | 416.541 | 546.478 | 52.6% |
宽导出/通配绑定 | 317.379 | 1,056.518 | 71.5% |
第一层独立细分定位到 eval.present:无模块 197.694 ms、共享 459.077 ms、私有 466.909 ms、宽导出 935.865 ms。bind_content 分别为 74.994、12.911、13.263、14.080 ms。这里的 present 是不透明内容调用展开与最终 Item 树呈现,不是 HTML Renderer。
求值二级探针:拷贝、调用与检查
另建第四个二进制,在四种 521 页完整负载上与原 detail 二进制同批交错重测:每侧预热一次、各三轮,共 32 次完整运行,全部逐文件校验。没有更换为 MemoryResources 小例,没有跳过克隆、结构检查、额度或来源展开。主批的普通 release 计时保持不变。
补充探针比同批 detail 的 wall 均值分别高 10.63%、9.82%、7.48%、9.16%;高频小范围计时的干扰明确存在,因此下面是补充探针自身的 Self 均值,不是可直接从普通 CLI 中减掉的“已证明优化收益”。
被测 Self 范围,ms | 无模块 | 共享图 | 私有图 | 宽导出 |
|---|---|---|---|---|
Item 显式 clone | 82.770 | 113.827 | 115.223 | 249.654 |
调用原型 Item clone | 28.732 | 50.377 | 51.265 | 92.688 |
调用 children clone | 19.112 | 29.777 | 30.159 | 64.970 |
checked body clone | 0.785 | 19.737 | 20.441 | 40.379 |
FunctionDef clone | 3.418 | 6.277 | 6.325 | 9.902 |
Invocation clone | 7.188 | 14.918 | 15.400 | 26.718 |
TypedExpr clone | 0.806 | 5.706 | 5.075 | 3.612 |
execute 剩余 Self | 57.742 | 141.926 | 142.861 | 250.421 |
implementation 剩余 Self | 11.360 | 19.006 | 19.805 | 33.837 |
content_count | 2.076 | 2.323 | 2.307 | 3.934 |
valid_structure | 1.979 | 2.472 | 2.463 | 4.458 |
check_value_size | 0.353 | 1.409 | 1.408 | 1.243 |
这些 Self 行不包含已插桩子范围,前三项也不是同一 clone 的重复记账;它们对应不同调用位置。合计 clone 行约为无模块 142.811 ms、共享 240.619 ms、私有 243.889 ms、宽导出 487.923 ms。未计时的其他 clone 不在这个合计里,也没有假设所有 clone 都能安全消除。
宽导出发生 105,031 次 execute、178,336 次所选 Item clone、88,647 次 prototype clone 与 88,647 次 children clone。这里是显式 clone 调用次数,不是底层被复制节点数;一次 Item clone 可以继续递归复制子树。结构校验 89,168 次仍仅约 4.46 ms,次数多不等于主要耗时。
代码与测量相互对应:
crates/notist-core/src/item.rs:382:Item 的派生 Clone 会复制 children Vec,以及 pending/origin 等拥有的数据。crates/notist-pipeline/src/code/eval.rs:420、:431:bind_content 先 node.clone,再递归重建 children,旧的整棵 children 拷贝随后被替换。同文件
:496–:498:present_node 同样先 clone Item,再递归呈现 children。同文件
:598–:602:present_call 分别克隆 children 与完整 prototype;execute 随后又重设 prototype 的 fields、pending、target、evaluation 和 children。同文件
:1023:每次实现查询返回 definition/body 的拥有副本;模块编译命中 comemo 不会自动消除这里的 checked body clone。
因此下一步应先审查 Item/内容调用的所有权流和可共享的不可变定义,减少“先整树复制、后覆盖 children/pending”的工作,同时保持 Analysis 不可变、扩展映射、错误边界和展开来源。不能根据本表直接跳过求值、删除结构/预算检查,或用缓存命中代替真实模块工作。
编译缓存与后端读取核对
负载 | 实际模块编译 | 实际编译 ms | 实际绑定 | 实际绑定 ms | 能力后端有界读取次数 |
|---|---|---|---|---|---|
完整 XIV | 0 | 0 | 0 | 0 | 1 |
无模块正文 | 0 | 0 | 0 | 0 | 521 |
共享组件图 | 18 | 0.620 | 139 | 0.275 | 539 |
私有模块图 | 5,120 | 133.009 | 5,632 | 20.944 | 5,641 |
宽导出 | 6 | 2.749 | 11 | 0.405 | 527 |
编译与绑定耗时取 coarse 实际未命中计数器的三轮均值,另存于 module-work-mean.json;有界读取次数取 detail。各轮及两种探针的模块工作次数完全相同。这不是把多个嵌套阶段相加得到的新总耗时。
私有图的有界读取总计约 15.126 ms;共享/宽导出各约 1.13 ms。源码查询仍要授权、计费并返回本轮稳定字节,但已没有全量版本扫描。优先继续削减 capability 首读检查并不能回收当前约半秒至一秒的求值成本。
后续优先级
模块/原生正文站:先改求值树的重复深拷贝与调用装配。 这是所有四个 521 页负载共有的热点;先保留语义,只改善拥有权/共享方式,再按本轮同输入、逐文件输出验收。
完整 XIV:先看文件发布和生成准备,而不是继续调 comemo。 优先确认唯一父目录的创建能否统一处理,减少重复 mkdir;旧目录删除仍要作为完整构建成本计入,不能仅移出计时伪装提速。发布的暂存、替换、失败保留旧站边界应保留。
其后优化逐页元数据/环境装配。 51,739 次解析、环境与源码登记有真实成本;已有上下文共享有效,site.data 转换不是每页重复执行。扩展路径/Route 重复验证值得进一步限定范围,不应以改变页面枚举或 site.data 模型掩盖。
暂不优先处理预算检查或重做模块缓存。 本轮实际绑定 miss 和硬预算/结构验证都很小;改消费者、删除安全检查、缩减正文不属于本轮分析或建议的收益来源。
插桩开销、验证与产物
普通计时、coarse、detail 使用三个独立二进制。下表是相对普通二进制均值的观测差异,含特性/代码生成差异和测量波动,不能视为已精确分离的纯计时器成本:
负载 | coarse 差异 | detail 差异 |
|---|---|---|
XIV | +0.40% | +3.89% |
无模块 | +0.02% | +0.15% |
共享 | +0.49% | +0.91% |
私有 | −0.10% | +0.80% |
宽导出 | −0.28% | +1.00% |
独立 self 计时只扣除已插桩子范围,包含未插桩工作和测量成本,不是 perf 采样 CPU Self;递归同名范围也按嵌套扣除。每次详细运行检查 Self 总和等于根 CLI 范围。
主批包含 25 次普通计时、两种探针各 15 次、15 次预热、3 次真实 JSON/TOML 正向控制,再加独立 cProfile 及两次完整 strace,共 76 次构建;独立求值补充再运行 32 次,合计 108 次。每次退出后核对全部相对路径、字节数和逐文件 SHA-256;全量输出均一致。正向控制检测到 4 次读取、2 次实际解析、2 次解析命中;五个主负载的语言 Data 读取均为零。
环境没有 perf/py-spy,本轮没有声称提供采样火焰图,也不作 RSS 排名。Python 工具 25 项与 std-only Rust 计时器 2 项测试通过;探针创建、编译、计时与校验分开执行。临时探针初次构建的命名空间修正及失败日志保留,没有改动生产源码。
原始目录:/tmp/opencode/notist-current-profile-20261103/。
manifest.json、environment.json:精确提交、CPU/工具链、构建环境、源码/输入/二进制指纹。samples.json、summary.json、integrity.json:每轮 wall/user/system、阶段、调用次数与分区复核。sources/、patches/、bin/、logs/、inventories/:源码快照、插桩补丁、二进制、完整日志、逐次逐文件输出清单。python.pstats、python-profile.json、strace.json:独立子进程函数 profile 与系统调用证据。evaluator-summary.json、evaluator-samples.json、evaluator-manifest.json:独立求值二级探针、同批基线、工作次数与二进制哈希;不混进主批普通样本。final-integrity.json:合并复核全部 108 次完整运行;dashboard.html为可切换负载的可视化,dashboard.jpg为截图。复现工具:
tools/profile_current.py、tools/profile_evaluator.py、tools/current_profile_probe.rs、tools/CURRENT_PROFILE.md;最新生产提交固定为214de5f,本次新增 profile 工具与报告另外留在工作区。