gjm/envi-code
1
0 Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity
Files
4f1ea72e4e54a737d7c901d7ca5ef4e8a2bb6c2b
envi-code/diagsession-cpu-analysis.md
T
company-desktop ae4cac5285 docs: 增加图纸打开慢的 CPU 采样分析（两轮 trace） 
现象：用 AutoCAD 打开含大量自定义实体的大图纸非常慢，需要定位热点后重构。

做法：解析 VS 诊断会话（.diagsession 内是 zip，含 sc.user_aux.etl），
用 xperf 导出采样与完整调用栈，按模块/函数/线程/调用链聚合。

两轮 trace：
- 第一轮在另一台机器采集（acdb23/acgs/ASMKERN225A，2021 系），
  该次构建的 PDB 已不可得，只能到「模块 + 调用链」级别：
  Parasolid 约 34%、内核+文件系统 17%、TBB 线程池 14%（基本空转）、
  SQLite 8.4%（栈内 17%，全部串行在主线程）、我们自己 arx 的代码 < 1%。
- 第二轮在本机重新采集（acdb19/modlr19/ASMKERN219A，R190 部署），
  PDB 与 bin 下二进制一致，28/28 模块符号匹配，得到函数级结论：
  AecDbEntityCommon::base_ViewportDraw 覆盖 74% 采样，
  Parasolid 约 43%，我们自己的代码约 2.5% 自耗时。
  GiDrawUtility::DrawPipe/DrawLoft/DrawRevolve 合计 20.5% 在每次绘制时重算几何；
  AecDbBDPipeBase::GetBooleanPart3D 12%；
  而 AecDbX3dPart::EnsureCreated/Rebuild 已在栈上却不命中，说明缓存脏判定有问题。
  dwgInFields/copyFrom 家族约 13.6%，载入期就把几何建出来了，
  且 CoreTools::StringToRegion 的栈里有 Ntfs/FLTMGR，解析 SAT 文本时还在读盘。

产出：
- diagsession-cpu-analysis.md：结论 + 优化优先级（P0/P1/P2）+ 环境干扰说明
- report-cpu-hotspots.md：工具生成的原始热点表（模块/函数/线程/调用链/时间线）

验证：仅在两轮 trace 上做了离线分析，未改任何源码，无编译与 CAD 实测。
已知限制：两轮 CAD 版本不同，百分比不能直接横比；当前部署是 Debug 构建，
热点分布与 Release 有差异，量化收益需用 Release 复测。

分析脚本 tools/perf_diagsession.py 因仓库 .gitignore 里已有 *.py 规则未一并提交。
2026-10-28 14:45:15 +08:00

13 KiB
Raw Blame History

打开大图纸慢 — CPU 采样分析

两轮 trace 的结论汇总。原始表格由 tools/perf_diagsession.py 生成，见 report-cpu-hotspots.md。

轮次 采集机 CAD / 模块 采样 符号
① 基线 另一台机器 acdb23 / acgs / ASMKERN225A（2021 系） 151,576 ≈ 151 s CPU 无（PDB 不匹配）→ 只有模块级
② 本机 本机 acdb19 / modlr19 / ASMKERN219A（R190 部署） 44,454 ≈ 43 s CPU 有（28/28 匹配，22 个是我们的）→ 函数级

0. 结论（TL;DR）

  1. 我们的 C++ 代码自身耗时几乎可以忽略（≈2.5 %）。慢的是它调用的 Parasolid 建模内核（两轮分别 34 % / 43 %）和每次绘制都重算几何这件事。
  2. 打开期的 CPU 几乎全在一条链上： acdb19 → 我们的实体 → 我们的 Draw3d/Draw3dSolid/GetBooleanPart3D → acdb19 → modlr19(ACIS) → Parasolid
  3. AecDbEntityCommon::base_ViewportDraw 覆盖 74.3 % 的采样——即"视口绘制"这一条路径。真正的优化点全部在这个函数下面。
  4. 两个可量化的浪费：
    • 每次绘制都重建实体几何：GiDrawUtility::DrawPipe/DrawLoft/DrawRevolve 合计 20.5 %； AecDbBDPipeBase::GetBooleanPart3D（布尔）12.0 %；但缓存层 AecDbX3dPart::EnsureCreated/Rebuild 已经在栈上（各 8.4 %）→ 缓存存在，却仍然每次判脏重建。
    • 载入期把 ACIS 文本解析成 Region：AecDbEwPipeBase::RegionAcisInDwgInFields 2.4 % + CoreTools::StringToRegion 2.2 %，且 StringToRegion 栈里带 Ntfs.sys/FLTMGR → 解析时还在读文件。
  5. 单线程串行：本轮 trace 里 98.0 % 的采样集中在 1 个线程（tid 10816），无并行；打开窗口 68 s 墙钟只用了 43 s CPU → 约 37 % 时间在等待。
  6. 环境干扰极大：Windows Defender（MsMpEng.exe）自己烧了 40 s CPU，和 acad 相当。测速必须先排除。

1. 怎么复现

:: 采集（WPR 比 VS 轻，不要用 VS 采，否则 devenv 抢核）
wpr -start CPU -filemode
::   ← 打开 DWG，等界面完全空闲
wpr -stop C:\temp\open.etl

:: 先校验符号（10 秒）
python tools\perf_diagsession.py C:\temp\open.etl --verify-only
:: 再出报告
python tools\perf_diagsession.py C:\temp\open.etl --out report-cpu-hotspots.md

关键：采完到分析完之间不要重新编译。脚本用 trace 里的 TimeDateStamp + SizeOfImage 去 <repo>/bin/Code2026/** 找同一份二进制和它旁边的 .pdb。 （上一版脚本误用「文件大小」比对 SizeOfImage，已修；否则永远匹配不上。）

.diagsession 的本质是 zip：sc.user_aux.etl（ETW 事件流 + 调用栈）+ .NET 元数据 + PDB 缓存 + 计数器。VS 的 PDBCache 只带 .NET 的 pdb，不含我们的，所以换机器采集就必然符号缺失。

2. 第二轮（本机，函数级）★

2.1 概况

  • trace 114 s；打开动作在 t≈41 s → t≈109 s（约 68 s 墙钟）
  • acad.exe 采样 44,454；带完整栈 42,888 ≈ 42.9 s CPU
  • 线程：tid 10816 占 97.99 %，其余线程加起来不到 1 % → 完全串行

2.2 模块自耗时

模块 采样 占比 说明
ASMKERN219A.dll 9,325 21.7 % Parasolid 内核
ASMBASE219A.dll 7,075 16.5 % Parasolid 基础
ntoskrnl.exe 6,811 15.9 % 内核（I/O、内存、锁）
msvcr100.dll 3,419 8.0 % VS2010 CRT——我们 arx 的分配器
ntdll.dll 2,453 5.7 % 堆/临界区
acdb19.dll 1,782 4.2 % AutoCAD 数据库
Ntfs.sys 1,325 3.1 % 文件系统
ASMINTR219A.dll 783 1.8 % Parasolid 求交
AecRxBase.arx 781 1.8 % 我们的代码
ASMBOOL219A.dll 576 1.3 % Parasolid 布尔
CoreCommand.arx 221 0.5 % 我们的代码

家族汇总：Parasolid（ASM*）≈43 %；内核 + 文件系统 + 杀软过滤 ≈24 %；msvcr100 8.0 %； 我们自己的 arx ≈2.5 %。

注意 msvcr100 8 %：它是 v100 工具集的 CRT，也就是我们 arx 的 new/delete/malloc。 这条说明临时对象的分配本身就是个可观成本，和"每次重算几何"互为因果。

2.3 我们的"骨架函数"（栈内出现率，每栈去重）

占比 函数
74.3 % AecRxBase.arx!AecDbEntityCommon::base_ViewportDraw
42.4 % AecRxBase.arx!AecDbCurveBase::subViewportDraw
31.9 % AecRxBase.arx!AecDbEntityBase::subViewportDraw
26.0 % CoreCommand.arx!AecDbEwEquipment::Draw3d
21.8 % CoreCommand.arx!AecDbEwEquipment::Draw3dSolid
18.7 % AecRxBase.arx!AcGiViewDraw::DrawPipe
16.0 % AecRxBase.arx!GiDrawUtility::DrawPipe
15.4 % CoreCommand.arx!AecDbGuardBar::Draw3d
13.5 % CoreCommand.arx!AecDbBDPipeBase::Draw3d
12.9 % AecRxBase.arx!AcGiViewDraw::DrawEntity
12.0 % CoreCommand.arx!AecDbBDPipeBase::GetDraw3dSolid
12.0 % CoreCommand.arx!AecDbBDPipeBase::GetBooleanPart3D
10.3 % CoreCommand.arx!AecDbWeir::Draw3d
9.7 % CoreCommand.arx!AecDbX3dPart::CreateDraw3dSolid
8.4 % CoreCommand.arx!AcDbX3dSolid::GetDraw3dSolid
8.4 % CoreCommand.arx!AecDbX3dPart::Rebuild
8.4 % CoreCommand.arx!AecDbX3dPart::EnsureCreated
8.0 % CoreCommand.arx!AecDbEwPipeBase::dwgInFields
7.8 % CoreCommand.arx!AcDbX3dSolid::ReCreate

2.4 驱动 Parasolid 的我们的函数（栈上第一个"我们的帧"）

采样 占比 函数 调用的 Parasolid 能力
5,378 12.5 % AecRxBase.arx!GiDrawUtility::DrawPipe ASMSWP（扫掠）
4,104 9.6 % AecRxBase.arx!AcGiViewDraw::DrawEntity 混合
2,483 5.8 % AecRxBase.arx!GiDrawUtility::DrawLoft 放样
1,236 2.9 % CoreCommand.arx!AecDbEwEquipment::Draw3dSolid ASMSKIN（蒙皮）
1,017 2.4 % CoreCommand.arx!AecDbEwPipeBase::RegionAcisInDwgInFields ←载入期
939 2.2 % CoreCommand.arx!CoreTools::StringToRegion ACIS 文本→Region
922 2.2 % AecRxBase.arx!GiDrawUtility::DrawRevolve 旋转
821 1.9 % CoreCommand.arx!AecDbBDPipeBase::GetBooleanPart3D ASMBOOL（布尔）
681 1.6 % AecRxBase.arx!(anonymous)::createRegion
524 1.2 % CoreCommand.arx!AcDbX3dSolid::CreateExtrude ASMSWP
463 1.1 % CoreCommand.arx!CoreTools::RegionToString Region→ACIS 文本
461 1.1 % CoreCommand.arx!NewExtrude::makeSolid
452 1.1 % CoreCommand.arx!TransformEntity
450 1.1 % CoreCommand.arx!NewRevolve::makeSolid
401 0.9 % CoreCommand.arx!AecDbEwPipeBase::RegionAcisoutDwgOutFields ←回写
216 0.5 % CoreCommand.arx!AecDbGuardBar::Draw3d
176 0.4 % CoreCommand.arx!AcDbX3dSolid::GetDraw3dSolid
148 0.3 % CoreCommand.arx!NewLoft::makeSolid

2.5 载入期（dwgInFields / copyFrom）也在建几何

这些函数直接调用 acdb19/modlr19 并进入 Parasolid：

采样 占比 函数
1,832 4.3 % CoreCommand.arx!AecDbEwPipe::dwgInFields
1,254 2.9 % CoreCommand.arx!AecDbEwPipeBase::copyFrom
624 1.5 % AecDbEwFitting::dwgInFields
623 1.5 % AecDbEwPipeBase::dwgInFields
546 1.3 % AecDbEwPipeBase::dwgOutFields
265 / 225 / 154 / 109 / 90 / 67 / 60 各 ≤0.6 % AecDbXSlab/XWall/Weir/Beam/GuardBar/EwEquipment/Column::dwgInFields

合计 ≈13.6 %：打开图纸时，读字段就直接把几何建出来了（不是画的时候才建）。

2.6 几条代表性调用链

GiDrawUtility::DrawPipe（12.5 % 的 Parasolid 入口）
  ASMKERN219A <- ASMSWP219A <- modlr19 <- acdb19 <- AecRxBase.arx <- CoreCommand.arx
              <- AecRxBase.arx <- acdb19 <- accore.dll <- acdb19 <- accore.dll <- acad.exe

AecDbEwEquipment::Draw3dSolid（2.9 %）
  ASMKERN219A <- ASMSKIN219A <- modlr19 <- acdb19 <- AecRxBase.arx <- CoreCommand.arx ...

AecDbBDPipeBase::GetBooleanPart3D（1.9 %）
  ASMKERN219A <- ASMBOOL219A <- modlr19 <- acdb19 <- CoreCommand.arx ...

CoreTools::StringToRegion（6.9 % 含以下两种形式）
  a) msvcr100 <- ASMKERN219A <- modlr19 <- acdb19 <- CoreCommand.arx   ← 解析 SAT 文本
  b) ntoskrnl <- Ntfs.sys <- FLTMGR.SYS <- ntoskrnl <- ntdll <- KernelBase
             <- mfc100u <- CoreCommand.arx                              ← 还在读文件！

2.7 我们自己的自耗时（能看到的只有这些）

采样 占比 函数
84 0.20 % AecRxBase.arx!std::_Tree::_Linsert
47 0.11 % AecRxBase.arx!std::_Tree::_Insert
37 0.09 % AecRxBase.arx!std::_Tree_val::_Parent
31 0.07 % CoreCommand.arx!AcDbObjectId::AcDbObjectId
19 0.04 % AecRxBase.arx!AecDbObjXDataMap::Resbuf2XDMap

std::_Tree 那些全是同一个容器：std::map<ATL::CStringT<wchar_t>, AecXData>（XData 表）。 合计约 0.6~0.8 %，都是 CString 字符串比较 + 红黑树插入。优化它能省一点，但不是主要矛盾。

3. 第一轮（另一台机器，只有模块级）

  • 137 s trace，acad.exe 151,576 采样 ≈ 151 s CPU，主线程占 65 %
  • 独占：Parasolid 系 34 %、内核+文件系统 17 %、TBB 线程池 14 %（基本空转）、 SQLite 8.4 %（栈内 17 %）、WPF 软件光栅化 3.3 %、我们的 arx <1 %
  • SQLite 17 % 全部在主线程串行，调用点集中在 CoreCommand.arx RVA 0x172675~0x1735fc （15 个调用点，最大单点 6.9 %），时间上从 t=8 s 持续到 t=99 s
  • 12 个 TBB worker 在 spin-then-yield（NtYieldExecution），主线程串行时仍在抢核

两轮的差异：第一轮走 SQLite 缓存库（2021 系），第二轮（R190 / CAD 2019）完全没有 sqlite 采样 （sqlite3_x64.dll / sqliteserver.dll 都加载了，但一次都没进）——说明 sqlite 只在特定版本/路径上生效， 这本身值得确认一下：R190 是否真的用上了 sqlite_query_cache 那套东西？

两轮的共同点：Parasolid 占 30~43 %，且都发生在"我们的实体 → acdb/modlr → ASM"这条链上； 我们自己的代码几乎不耗 CPU。

4. 优化优先级

优先级 动作 依据 预期
P0 查清 AecDbX3dPart::EnsureCreated/Rebuild 为什么每次都重建。缓存框架已在（8.4 % 在栈上），但每次绘制仍走到 Rebuild → 脏标记/RecomputeFlags/参数签名判定有问题 §2.3 §2.4 直接吃掉 base_ViewportDraw 74 % 里的大头
P0 GiDrawUtility::DrawPipe / DrawLoft / DrawRevolve 的产物缓存（12.5+5.8+2.2 = 20.5 %）：参数不变就不要重新扫掠/放样/旋转 §2.4 20 % 量级
P0 AecDbBDPipeBase::GetBooleanPart3D 布尔结果缓存（管道/管件布尔 12.0 %） §2.4 10 % 量级
P1 载入期惰性化：dwgInFields/copyFrom 阶段不要立刻 RegionAcisInDwgInFields /
StringToRegion 把 ACIS 文本建出来，改成首次绘制时再做（并可并行） §2.5 ≈13.6 %
P1 StringToRegion 里的文件 I/O 需要确认（栈里有 Ntfs/FLTMGR）：为什么解析 SAT 文本会读盘？ §2.6 未知，可能不小
P1 dwgOutFields / RegionToString 回写（1.3+1.1 %）：打开后马上又序列化一遍？ §2.4 §2.5 小
P2 XData 容器 std::map<CString, AecXData> → unordered_map 或按对象 id 缓存 §2.7 0.5 % 左右
P2 （第一轮）TBB 并行粒度 / 串行期缩线程池；R190 单线程，若要提速可考虑把实体建几何并行化 §3 需先解决 P0 缓存
P2 抑制打开期间的 WPF 预览重绘（第一轮 3.3 %） §3 小

5. 环境干扰（必须先处理才能量化收益）

轮次 与 acad 同时吃 CPU 的进程
① MsMpEng 31,656、devenv 28,334、dwm 18,461
② MsMpEng 40,310（≈40 s CPU，和 acad 相当）、devenv 17,271、dwm 11,423、Taskmgr 6,923
  • Windows Defender 在两轮里都烧掉约一个核
  • 第一轮是在 Visual Studio 里采的，devenv 自己也在抢 CPU

测速前：给 DWG 目录、sqlite 目录加 Defender 排除项；关 VS / 任务管理器 / 其它重程序。 否则「打开 40 s 还是 30 s」这种对比没有意义。

6. 限制与下一步

  1. 两轮 trace 的 CAD 版本不同（一个 acdb23，一个 acdb19/R190），横向百分比不能直接比， 但"Parasolid 占大头 + 绘制期重建几何 + 我们代码不耗时"这个结论一致。
  2. 当前部署是 Debug 构建（无内联、带调试检查），热点分布与 Release 会有差异。 定位用 Debug 没问题；量化收益请用 Release 复测（Release-x64-R190 目前只编了 1 个模块，需要补齐）。
  3. 采样只能回答"时间花在哪"，回答不了"调用了多少次"。 若需要调用次数（比如"同一个实体在一次 open 里被 draw 了几次"），得在 base_ViewportDraw / EnsureCreated 上加计数器，或用 ETW 自定义事件。
  4. 下一步建议：先给 base_ViewportDraw 与 AecDbX3dPart::EnsureCreated 加轻量计数/耗时统计 （只在 Debug 开），统计"每个实体被 draw 次数 / Rebuild 次数 / 命中率"，再决定 P0 的缓存策略。
Reference in new issue View Git Blame Copy Permalink