概要:
前三篇围绕 logs_2.sqlite 的 TRACE 日志、WAL 写入和 checkpoint 做了多轮排查:
- 第一篇:检查数据库并用 Trigger 临时拦截 TRACE/DEBUG
- 第二篇:用 Procmon 统计实际写入量并确认官方修复
- 第三篇:继续分析 194 MB/小时写入和 WAL checkpoint
随着监控项目增加,需要先划清每种工具究竟在回答什么问题:
| 工具 | 主要回答的问题 |
|---|---|
| Procmon | Codex 向哪些文件写了多少数据? |
| PerfMon | Codex 消耗了多少 CPU、物理内存和私有内存? |
| 任务管理器 / PerfMon GPU 计数器 | 窗口动画和渲染是否占用 GPU? |
| SQLite 查询 | 这些写入由多少日志、哪些 target 产生? |
| 人工记录 | 同样任务花了多久,界面是否卡顿? |
单独一项数据通常无法解释问题。例如 Procmon 记录到一小时写入 90 MB,只能说明发生了 90 MB 的逻辑写入,无法判断是任务较多、日志条数较多,还是少量日志触发了较强的 SQLite 写放大。
这篇先保留手工流程,因为它能解释每个数字的来源,也方便修改过滤条件或复核异常结果。如果只想一键开始、停止并生成报告,可以直接使用另一篇的 Codex Monitor 一键监控工具;它自动执行的仍然是本文这些监控项目。
- 概要:
- 1. 最小监控项目
- 2. Procmon:监控 SQLite 写入
- 3. PerfMon:监控 CPU 和内存
- 4. 检查思考状态下的 UI 和 GPU 开销
- 5. SQL:解释写入量的来源
- 6. 30 分钟 A/B 测试流程
- 7. 一次实际 PerfMon 记录
- 8. 如何组合判断
- 结论
1. 最小监控项目
并不是计数器越多越好。当前问题只需要保留以下项目:
| 类别 | 必要指标 | 可选指标 |
|---|---|---|
| 磁盘 | 主库、WAL、SHM 的 Write Bytes 和文件大小变化 |
checkpoint 次数 |
| CPU | 所有 Codex 桌面端进程的 % Processor Time |
CPU 峰值、P95 |
| 内存 | Working Set - Private、Private Bytes |
Handle Count、Thread Count |
| GPU | GPU 利用率、GPU Engine、GPU 显存 | dwm.exe GPU 利用率 |
| SQL | sqlite_sequence.seq、当前保留行数、level + target 分布 |
日志正文总字节数 |
| 体验 | 任务完成时间、界面卡顿 | 窗口可见/最小化差异 |
其中句柄数、线程数、网络流量等指标只有在出现持续增长、断线或卡死时才需要加入,平时无需全部采集。
2. Procmon:监控 SQLite 写入
过滤设置
管理员身份打开 Process Monitor,按 Ctrl + E 停止捕获、Ctrl + X 清空记录,然后设置:
Path begins with C:\Users\你的用户名\.codex\logs_2.sqlite Include
Operation is WriteFile Include
Operation is FlushBuffersFile Include
Operation is SetEndOfFileInformationFile Include
在 Filter 菜单中启用 Drop Filtered Events,并只保留文件系统活动,避免无关事件占用内存和 Procmon 日志空间。不要添加 Result is SUCCESS;结束后在 CSV 或 File Summary 中只统计成功事件即可。
监控结束后打开 Tools → File Summary → By Path,分别记录:
1 | logs_2.sqlite |
的 Write Bytes,再记录三个文件的起止大小。
写入量不等于文件增长量
Procmon 的 Write Bytes 是应用层逻辑写入,可能包含:
- WAL 中同一页面的多个版本;
- checkpoint 后写回主库;
- 主库已有页面的覆盖更新;
- 写入后又被日志清理机制删除的数据。
因此:
1 | Procmon 总写入量 ≠ 文件净增长量 ≠ SSD 最终 NAND 写入量 |
文件只增长 20 MB,并不代表这一小时只写了 20 MB;反过来,90 MB/小时的逻辑写入也不能直接换算成 90 MB 的 SSD 损耗。
checkpoint 调查是可选项目
只有在 WAL 持续变大、主库写入明显异常时,才需要额外分析以下事件:
Operation is FlushBuffersFile
Operation is SetEndOfFileInformationFile
FlushBuffersFile 只能说明应用发出了 Flush 请求,不等于磁盘已经完成一次物理刷写,也不能把每个 Flush 当作一次 checkpoint。SetEndOfFileInformationFile 表示文件逻辑末尾发生设置或扩展,也不是 checkpoint 标记。
可以把连续的主库 WriteFile 与其后的主库 Flush/SetEnd 归为一个 checkpoint-like 批次,用来近似观察 WAL 写回主库的节奏。想做到更精确,只能结合 SQLite 自己的 checkpoint 状态、WAL 页数与应用内部埋点;仅靠外部文件事件无法得到严格的一一对应次数。
3. PerfMon:监控 CPU 和内存
按 Win + R,输入 perfmon,在“数据收集器集 → 用户定义”中新建性能计数器收集器。
选择进程
Codex Windows 桌面端采用多进程结构,进程列表通常包括:
1 | ChatGPT.exe(多个) |
应选择来自 WindowsApps\OpenAI.Codex_... 的桌面端进程,排除 VS Code 扩展目录中的 codex.exe。
优先使用 Process V2,它会在实例名称中显示 PID,例如:
1 | ChatGPT:15968 |
必要计数器
添加:
1 | Process V2 |
% Processor Time:进程在采样区间内占用的处理器时间。100% 相当于占满一个逻辑处理器,多线程进程可能超过 100%。Working Set - Private:当前实际驻留在物理 RAM、并且只归该进程使用的内存。Private Bytes:进程已经承诺使用的私有虚拟内存,可能位于 RAM,也可能被换出到页面文件。它更适合辅助判断长期内存泄漏。
建议设置:
1 | 采样间隔:5 秒 |
CPU 秒怎么理解
一个逻辑处理器满负荷运行一秒,就是一个 CPU 秒。
如果 30 分钟内所有 Codex 进程的平均 CPU 合计为 3.37%,则:
1 | 累计 CPU 秒 = 3.37 ÷ 100 × 1800 |
同样工作负载下,CPU 秒越少,说明本地处理开销越低。
PerfMon 曲线允许为每条线设置不同“比例”。曲线看起来位于 70,并不代表 CPU 是 70% 或内存是 70 MB。精确数据应查看“最新、平均、最小、最大”,或直接分析原始 BLG。
多个进程的平均内存可以相加,但不能把每个进程各自的最大值相加后当作总体峰值——这些峰值可能发生在不同时间。总体峰值必须按相同采样时刻先求和,再从总和曲线中取最大值。
4. 检查思考状态下的 UI 和 GPU 开销
CPU 日志正常并不能排除 UI 渲染问题,因为部分动画可能主要使用 GPU。
先用任务管理器快速检查
打开“任务管理器 → 详细信息 → 右键表头 → 选择列”,启用:
1 | GPU |
按 GPU 排序,观察多个 ChatGPT.exe。承担渲染的进程通常会显示类似:
1 | GPU 0 - 3D |
同一任务内做可见/最小化对照
选择一个能持续几分钟的任务:
- Codex 窗口保持可见 60 秒;
- 窗口最小化 60 秒;
- 再次显示窗口 60 秒;
- 对比三个阶段的
ChatGPT.exe、codex.exe和dwm.exeCPU/GPU。
| 现象 | 更可能的原因 |
|---|---|
| 可见时 CPU/GPU 上升,最小化后立即下降 | UI 动画、重绘或桌面合成 |
ChatGPT.exe 上升,codex.exe 基本不变 |
桌面界面或渲染进程 |
codex.exe 上升,最小化后也不下降 |
本地后端处理,而非可见 UI |
dwm.exe 只在窗口可见时上升 |
Windows 桌面合成 |
| 三个阶段没有明显差异 | 当前版本/界面大概率没有该问题 |
需要保存 GPU 时间线时,再在 PerfMon 中添加:
1 | GPU Engine |
GPU Engine 的实例名称通常带 PID,可以和任务管理器中的 ChatGPT.exe 对应。
Codex 桌面端的 Pet 是可选动画。官方 Pets 文档 说明,在 Windows 开启“辅助功能 → 视觉效果 → 动画效果:关闭”后,Pet 会使用静态帧。没有启用 Pet 时,不会看到这类明显动画。
5. SQL:解释写入量的来源
Procmon 已经回答“写了多少字节”,SQL 不需要重复统计文件 I/O。SQL 的任务是回答:
这些写入由多少日志产生?哪些模块在写?日志写入后是否又被大量清理?
起止快照
测试开始前和结束后各执行一次:
1 | SELECT |
记录后关闭 DB Browser,再开始 Procmon/PerfMon 捕获,避免长时间读取连接影响 WAL checkpoint。
结束后计算:
1 | 累计 ID 增量 = 结束 seq - 开始 seq |
sqlite_sequence 不是严格插入计数器
sqlite_sequence.seq 是 AUTOINCREMENT 的历史 ID 高水位。SQLite 只保证 ID 总体递增,不保证连续;失败或被忽略的插入可能留下空洞。因此更准确的名称是“累计 ID 消耗量”,不是绝对精确的成功插入行数。
没有 Trigger、没有唯一约束冲突时,测试前后的 seq 差通常可以近似新增日志量。启用 RAISE(IGNORE) Trigger 后,应将它视为对照指标,而不是严格计数。
按 level 和 target 查看来源
把测试开始时的 seq 代入:
1 | SELECT |
如果一小时内日志清理已经删除了早期新增行,这个结果只能代表测试结束时仍然保留的新增日志,不能保证覆盖完整一小时。不过它仍然适合寻找占比最高的模块,例如:
1 | TRACE codex_app_server::outgoing_message |
不要为了获得严格的整小时 target 计数再添加一个统计 Trigger,因为它本身也会产生数据库写入,污染 Procmon 测试。
日志正文大小是可选项
如果需要区分“很多条短日志”和“少量超大 payload”,先查看表结构:
1 | PRAGMA table_info(logs); |
再对实际保存正文的字段计算 SUM(length(字段名)),可得到近似写放大:
1 | 写放大倍数 ≈ Procmon Write Bytes ÷ 新增日志正文总字节 |
日常复测只统计 level + target 通常已经足够。
不要在监控过程中主动执行 PRAGMA wal_checkpoint(...)。它可能改变正在观察的 checkpoint 和 WAL 状态。
6. 30 分钟 A/B 测试流程
测试前统一条件
每轮都保持:
- 相同 Codex 版本;
- 相同任务内容和数量;
- 相同采样间隔和测试时长;
- DB Browser 在采集期间完全关闭;
- 重启 Codex 后等待约 2 分钟完成预热;
- 分别保存 PML、BLG 和 SQL 起止快照。
建议测试顺序
| 测试 | 条件 | 目的 |
|---|---|---|
| A | 不发送任务,空闲 30 分钟 | 得到真正的后台基线 |
| B | 默认配置,执行固定任务 | 得到正常工作负载 |
| C | 只启用模块日志过滤,重复固定任务 | 判断源头过滤是否有效 |
| D | 只启用 Trigger,重复固定任务 | Trigger 仅作为兜底对照 |
不要同时启用模块过滤和 Trigger,否则写入下降后无法判断是哪一个措施起效。
当前已经取得的写入记录包括:
| 条件 | Procmon 写入量 |
|---|---|
| Trigger 生效、此前闲时 | 10.14 MB/小时 |
| 无 Trigger、任务较多 | 194 MB/小时 |
| 无 Trigger、任务较少 | 约 90 MB/小时 |
后两轮任务量不同,因此不能直接得出“写入已经减半”。还需要一次无任务的 30 分钟基线,并使用 seq 增量或固定任务数量做归一化。
每轮最终记录表
| 指标 | A | B |
|---|---|---|
| 测试时长 | ||
| 任务数量/完成时间 | ||
| Procmon 总写入量 | ||
| 主库/WAL 分别写入量 | ||
| 主库/WAL 起止大小 | ||
| 累计 ID 增量 | ||
| 当前保留行变化 | ||
| 每个 ID 写入字节 | ||
| 平均/峰值 Private Working Set | ||
| Private Bytes 首尾变化 | ||
| 累计 CPU 秒 | ||
| GPU 可见/最小化差异 | ||
| 界面卡顿情况 |
7. 一次实际 PerfMon 记录
一次 30 分钟、5 秒采样的 BLG 中,共记录了 9 个 Codex 桌面端进程、361 个采样点。按每个时刻汇总后的结果为:
| 指标 | 结果 |
|---|---|
| 累计 CPU | 60.7 CPU 秒 |
| 平均 CPU | 3.37% 个单核 |
| CPU 中位数 | 0.62% |
| CPU 峰值 | 82.3% 个单核,约一个采样区间 |
| 平均 Private Working Set | 629.7 MiB |
| 内存峰值 | 1159.5 MiB |
| 最后一分钟平均内存 | 601.7 MiB |
| 结束内存 | 597.7 MiB |
CPU 主要消耗集中在前 15 分钟,后 15 分钟接近空闲。内存峰值出现在开始后约 20 秒,随后回落到约 600 MiB,没有表现出持续单向增长。
这说明:
- 本地 CPU 以短暂突发为主,没有持续高占用;
- 约 1.16 GiB 的峰值是短暂分配,不能仅凭峰值判定泄漏;
- 应比较第一/最后一分钟平均值,而不是只比较第一个和最后一个采样点;
- 此次 BLG 未包含 GPU,不能据此排除 GPU 渲染问题。
8. 如何组合判断
| 组合现象 | 更可能的解释 |
|---|---|
Procmon 写入高,seq 增量也高 |
日志数量本身较多 |
Procmon 写入高,seq 增量不高 |
单条日志较大或 SQLite 写放大明显 |
seq 增量高,COUNT(*) 基本不变 |
大量插入后又被清理 |
| WAL 写入高,主库定期集中写入 | 正常 WAL + checkpoint 周期,需结合频率判断 |
| 文件净增长小,Write Bytes 很大 | 主要在覆盖旧页面或写入后删除 |
| Private Working Set 波动,Private Bytes 稳定 | 缓存、驻留集裁剪或临时分配 |
| Private Bytes 与结束内存持续多轮上升 | 需要继续调查内存泄漏 |
| CPU/GPU 在窗口最小化后立即下降 | UI 动画、重绘或桌面合成 |
codex.exe 高占用且最小化无变化 |
后端本地处理,而不是可见 UI |
| 写入量下降但每个 ID 写入字节不变 | 主要因为日志/任务数量减少 |
| 每个 ID 写入字节也明显下降 | 写放大、checkpoint 或日志内容得到改善 |
最终应该优先关注用户能感知的结果:同样任务是否更快、界面是否更流畅、数据库和 WAL 是否失控增长。单纯出现一个 CPU 或内存尖峰,不等于存在性能问题。
结论
这套手工流程的价值,是知道每个数据从哪里来、能说明什么以及不能说明什么。日常复测不需要每次分别打开全部工具,可以交给 Codex Monitor 自动采集;自动报告发现异常、需要修改口径或核对原始数据时,再按本文使用:
1 | Procmon:写了多少、写到哪里 |
其中最重要的对照指标不是单独的 MB/小时,而是:
1 | 相同任务下的总写入量 |
补齐真正的空闲基线后,再决定是否需要按模块过滤日志或重新启用 Trigger。90 MB/小时的逻辑写入本身并不紧急,先确认它来自后台固定写入还是正常任务活动更重要。
评论