diff --git a/SourceCode/Code2026/CoreLibrary/AecDbEwPipeBase.cpp b/SourceCode/Code2026/CoreLibrary/AecDbEwPipeBase.cpp index a5d7c67..166c0d2 100644 --- a/SourceCode/Code2026/CoreLibrary/AecDbEwPipeBase.cpp +++ b/SourceCode/Code2026/CoreLibrary/AecDbEwPipeBase.cpp @@ -1275,6 +1275,18 @@ Acad::ErrorStatus AecDbEwPipeBase::BaseCurveDwgOutFields(AcDbCurve* pBaseCurve,A Acad::ErrorStatus AecDbEwPipeBase::RegionAcisoutDwgOutFields(AcDbDwgFiler* pFiler) const { // Phase 0 计数:回写(Region -> SAT 文本)的次数与耗时 + // 诊断:AEC_WRITEBACK_TRACE=1 时抓一次调用栈,确认开图期是谁在回写实体 + { + static bool s_bTraced = false; + if (!s_bTraced) + { + s_bTraced = true; + const char* pszTrace = ::getenv("AEC_WRITEBACK_TRACE"); + if (pszTrace != NULL && pszTrace[0] != '0') + SectionPerf::TraceCallStack("EwPipe::RegionAcisout (first call)", 2); + } + } + SectionPerf::Scope perfScope("EwPipe::RegionAcisout"); SectionPerf::NoteWriteBack("EwPipe::RegionAcisout"); diff --git a/SourceCode/Code2026/CoreLibrary/SectionPerfCounter.cpp b/SourceCode/Code2026/CoreLibrary/SectionPerfCounter.cpp index 3f3fa60..f8c7ffd 100644 --- a/SourceCode/Code2026/CoreLibrary/SectionPerfCounter.cpp +++ b/SourceCode/Code2026/CoreLibrary/SectionPerfCounter.cpp @@ -344,6 +344,52 @@ namespace SectionPerf } } + void TraceCallStack(const char* pszTag, int nSkip) + { + typedef USHORT(WINAPI* PFN_CaptureStack)(ULONG, ULONG, PVOID*, PULONG); + static PFN_CaptureStack s_pfn = NULL; + static bool s_bTried = false; + if (!s_bTried) + { + s_bTried = true; + HMODULE hNtdll = ::GetModuleHandleA("ntdll.dll"); + if (hNtdll != NULL) + s_pfn = (PFN_CaptureStack)::GetProcAddress(hNtdll, "RtlCaptureStackBackTrace"); + } + if (s_pfn == NULL) + return; + + void* frames[24]; + ::memset(frames, 0, sizeof(frames)); + const USHORT nGot = s_pfn((ULONG)(nSkip > 0 ? nSkip : 0), 24, frames, NULL); + + std::string out = "\n[stack] "; + out += (pszTag != NULL ? pszTag : "?"); + out += "\n"; + char szLine[1024]; + for (USHORT i = 0; i < nGot; ++i) + { + const DWORD64 nAddr = (DWORD64)frames[i]; + HMODULE hMod = NULL; + if (!::GetModuleHandleExW(GET_MODULE_HANDLE_EX_FLAG_FROM_ADDRESS | GET_MODULE_HANDLE_EX_FLAG_UNCHANGED_REFCOUNT, + (LPCWSTR)nAddr, &hMod) || hMod == NULL) + continue; + + WCHAR szPath[MAX_PATH]; + ::memset(szPath, 0, sizeof(szPath)); + ::GetModuleFileNameW(hMod, szPath, MAX_PATH); + const WCHAR* pszBase = wcsrchr(szPath, L'\\'); + pszBase = (pszBase != NULL) ? pszBase + 1 : szPath; + + char szMod[MAX_PATH * 2]; + ::memset(szMod, 0, sizeof(szMod)); + ::WideCharToMultiByte(CP_ACP, 0, pszBase, -1, szMod, sizeof(szMod) - 1, NULL, NULL); + sprintf_s(szLine, sizeof(szLine), " %-28s +0x%llx\n", szMod, (unsigned long long)(nAddr - (DWORD64)hMod)); + out += szLine; + } + AppendReport(out.c_str()); + } + void AppendReport(const char* pszText) { if (pszText == NULL) diff --git a/SourceCode/Code2026/inc/SectionPerfCounter.h b/SourceCode/Code2026/inc/SectionPerfCounter.h index fe7bcfa..b8f3d43 100644 --- a/SourceCode/Code2026/inc/SectionPerfCounter.h +++ b/SourceCode/Code2026/inc/SectionPerfCounter.h @@ -76,9 +76,12 @@ namespace SectionPerf // 打印 + 写文件 void Dump(); - // 只追加文本到 %TEMP%ec_section_perf.txt(供其它模块复用同一份报告) + // 只追加文本到 %TEMP%\aec_section_perf.txt(供其它模块复用同一份报告) void AppendReport(const char* pszText); + // 抓一次调用栈写进报告,用于定位"谁在开图期回写实体"这类问题 + void TraceCallStack(const char* pszTag, int nSkip = 1); + // 清零 void Reset(); } diff --git a/pipe-section-region-performance-plan.md b/pipe-section-region-performance-plan.md index a69142b..9bf742b 100644 --- a/pipe-section-region-performance-plan.md +++ b/pipe-section-region-performance-plan.md @@ -277,13 +277,61 @@ clone 成本可以忽略,说明"每次无论命中与否都发 clone"这个保 #### 仍未解决 -1. `EwPipe::RegionAcisout` 仍是 **1140 次 / 2.38 s**,开图期间把几何又序列化回 SAT, - 与缓存无关,应单独立项。 +1. `EwPipe::RegionAcisout` 仍是 **1140 次 / 2.38 s**——已查明原因,见下节。 2. `Fitting::GetSection` 在**开图**阶段只有 232 次调用(0.13 s),收益很小; 它的价值可能在绘制/平移时,需要另一次针对"打开后操作"的测量才能确认。 3. `StringToRegion` 仍有 1570 次未命中(唯一文本 1562),这部分是真实的不同截面, 想再提升只能靠业务层的 key,暂不做。 +### 开图期 1140 次回写(RegionAcisout)的成因 + +用 `AEC_WRITEBACK_TRACE=1` 抓了一次调用栈(`SectionPerf::TraceCallStack`,输出在报告文件里): + +``` +aecrxbase.arx +0x21cb4 AecDbCurveBase::subViewportDraw +aecrxbase.arx +0x28905 AecDbEntityCommon::base_ViewportDraw +corecommand.arx +0x7ddcef ← 绘制路径里的我们的代码(未解析到符号) +corecommand.arx +0x7e09d0 +corecommand.arx +0x7e1300 +acdb23.dll +0x97a6b +ac1st23.dll +0x19847 +corecommand.arx +0x58f051 ← AecDbEntityCommon::base_DeepClone +acdb23.dll +0x558e3 AcDbObject::dwgOut +corecommand.arx +0x58eb33 AecDbEwPipeBase::dwgOutFields +corecommand.arx +0x59627b AecDbEwPipeBase::RegionAcisoutDwgOutFields +``` + +**结论:不是保存,是"绘制期深拷贝"。** + +`AecRxBase/AecDbEntityCommon.cpp:1265`(`base_DeepClone`)用最朴素的方式实现深拷贝: + +```cpp +AcDbDeepCloneFiler filer; +GetMe()->dwgOut(&filer); // → dwgOutFields → acisOut 写临时 SAT 文件 +filer.seek(0L, AcDb::kSeekFromStart); +pClone->dwgIn(&filer); // → dwgInFields → acisIn 读回来 +``` + +于是**每次绘制期克隆实体,截面都要"写一个 SAT 临时文件、再读回来"**。 +1140 次 × 2.08 ms ≈ 2.38 s,全部发生在开图的绘制阶段。 + +(读的那一半现在已被 kText 缓存吃掉;剩下的是 `acisOut` 写文件这一半。) + +触发点:绘制路径里有 `clone()`(栈帧在 corecommand.arx 内,未解析到符号)。 +代码里一处明确的可疑点是 `AecDbX3dPartEntity::subGetTransformedCopy` +(`AecDbX3dPartEntity.cpp:757` 直接 `clone()`),但**尚未证实它就是本次的调用者**, +需要用 PDB 解析上面三个 RVA 才能钉死。 + +可选修法(都需要动 `base_DeepClone` 的契约,属于结构性改动,建议单独立项): + +| 方案 | 做法 | 风险 | +| --- | --- | --- | +| A | 用 `pFiler->isKindOf(AcDbDeepCloneFiler::desc())` 识别深拷贝,`dwgOutFields` 只写占位符不落盘;克隆完成后由 `base_DeepClone` 用 `m_pRegion->clone()` 在内存里补 | 要给 `AecDbEntityCommon` 加一个"重数据拷贝"的虚钩子,影响面大 | +| B | 缓存里同时保存每份 SAT 的原文,`dwgOutFields` 直接写缓存文本,省掉 `acisOut` | 若 `m_pRegion` 在 restore 之后被就地修改过,写出去的是旧几何——必须先审计全库对 `m_pRegion` 的写操作 | +| C | 维持现状 | 每次开图多 ~2.4 s(占 98 s 的 2.4%) | + +**A 与 B 都需要先做代码审计**,不适合和本缓存改动混在一起。 + ### Phase 2:临时目录治理(可选,止血) Phase 1 之后残余落盘只剩"每个唯一截面一次",收益小;但如果现场仍被杀软拖慢,可做这一步: