工业相机长期运行崩溃调查 - handle 泄漏篇
· 小村 豪 · Windows 开发, 故障排查, 工业相机, handle 泄漏, 日志设计
当 Windows 应用在长时间运行后突然崩溃时,很多人第一反应都会怀疑是内存泄漏。 不过实际上,handle 泄漏 才是真正的元凶,直到数周之后才以二次故障的形式浮出水面,这样的案例也不少见。
本文要介绍的是一个真实案例:某个用于控制工业相机的 Windows 应用,在连续运行约 1 个月之后突然崩溃。经过排查,最终确认原因是 相机重新连接相关失败路径中发生的 handle 泄漏。
上篇整理 handle 泄漏是什么、这次事件是如何排查的,以及为了防止再次发生应该保留哪些日志。 下篇会在 工业相机控制应用运行一个月后突然崩溃时(下篇) - 什么是 Application Verifier 与异常路径测试基础设施的做法 中,介绍异常路径测试基础设施的内容。
文中隐去了一些专有名词和部分日志字段,但这里的思路本身,在 Windows 设备控制类应用中具有相当高的通用性。
目录
- 先说结论(一句话)
- 什么是 handle 泄漏
- 2.1. 这里所说的「handle」
- 2.2. 为什么只有长时间运行后才会表面化
- 2.3. 与内存泄漏的区别
- 案例:工业相机控制应用在 1 个月后突然崩溃
- 3.1. 出现的症状
- 3.2. 最先查看的指标
- 3.3. 真正的泄漏位置
- 如何排查
- 4.1. 不等待以月为单位的再现,先压缩时间
- 4.2. 用
Handle Count的斜率来看 - 4.3. 查看
create/open与close/dispose的对应关系 - 4.4. handle 泄漏要找的不是「崩溃的位置」而是「泄漏的位置」
- 为防止再次发生所需的日志
- 5.1. 首先应保留的最小集合
- 5.2. 实际强化的日志
- 5.3. 该以什么粒度采集
- 大致的使用区分
- 总结
- 参考资料
1. 先说结论(一句话)
- 对于只在长时间运行后才崩溃的控制应用,除了
Private Bytes,一定还要看Handle Count - handle 泄漏往往不藏在正常路径中,而是潜伏在
timeout/reconnect/ 中途失败 / early return 这类路径里 - 真正崩溃的那一行,往往不是泄漏发生的地方,而是之后无法再创建新 handle 的地方
- 最先需要的日志包括:
operation/session的上下文、进程的handle count、resource 的open/close对应关系,以及 Win32 / HRESULT / SDK 错误 - 与等待以月为单位的再现相比,把连接、断开、重新连接、失败路径放进短循环里跑上几千次会快得多
- 下篇会提到的 Application Verifier 相当有效,但在此之前,先让自己的日志能够追踪 lifetime 被破坏的过程 才是基础
总而言之,这类案件应该优先做的, 不是盯着「运行很久之后崩溃了」这件事本身,而是把资源增长方式和失败路径变成可观测的形式。
handle 泄漏被发现的时候,往往已经戴上了二次故障的面具。 因此,如果只盯着崩溃瞬间的异常,很容易走向完全偏离方向的排查思路。
2. 什么是 handle 泄漏
2.1. 这里所说的「handle」
这里说的 handle,是 Windows 进程用来引用 OS 资源的标识符。 典型对象包括以下这些。
| 分类 | 示例 |
|---|---|
| 内核对象 | event、mutex、semaphore、thread、process、waitable timer |
| I/O 相关 | 对 file、pipe、socket、device 的 open |
| 设备控制中常见的 | 相机 SDK 内部的 event、与 callback 注册相关联的等待对象、与采集线程相关的 handle |
在控制类应用中,特别容易出问题的是 「为某个操作临时打开的资源,在中途失败的路径上忘记关闭」 这种模式。
典型的流程是这样的:
- 每次重新连接都会创建一个 event
- callback 注册或采集启动在中途失败
- 在 success path 中会被 close,但在 failure path 中不会
- 平时的短时间测试大多只会走成功路径,因此容易被忽略
无论是代码评审还是实际运行中,这类问题都相当常见。
2.2. 为什么只有长时间运行后才会表面化
handle 泄漏未必会在一次失败中就轰然崩溃。 更麻烦的其实是 每次失败只泄漏一个 这种斜率很小的泄漏。
flowchart LR
A[正常运行] --> B[偶尔出现 timeout / reconnect]
B --> C[在失败路径中创建 Event Handle]
C --> D[没有调用 CloseHandle]
D --> E[Handle Count 略微增加]
E --> F[重复几百次]
F --> G[CreateEvent / SDK open 失败]
G --> H[在别的地方崩溃 / 停止]
如果每次 reconnect 只泄漏一个,几分钟内什么都不会发生。 但是,在 24/7 运行的设备控制应用中,timeout、重新初始化、断线恢复这类边界条件会反复出现。 结果就变成了一种奇怪的现象:只有在数周之后才会表面化。
这里重要的一点是:handle 泄漏本身未必就是崩溃的那一行。 更常见的破坏方式是这样的:
- 创建新 event / file / thread 的 API 调用失败
- SDK 内部无法创建所需的资源,只返回一个通用的失败代码
- 失败后的错误处理比较薄弱,踩到
null/ invalid handle 而崩溃 - timeout 增多,结果被 watchdog 或上层控制逻辑 kill 掉
也就是说,崩溃发生的位置是「最后的受害者」,未必是「最初的犯人」。
2.3. 与内存泄漏的区别
长时间运行后出现的故障,第一反应通常是怀疑内存泄漏。 这种反应本身很自然,但 handle 泄漏往往需要从另一个维度去看,才能更快找到问题。
| 视角 | 内存泄漏 | handle 泄漏 |
|---|---|---|
| 最先看的指标 | Private Bytes、Commit、Working Set |
Handle Count |
| 典型症状 | 内存紧张、paging、变慢、OOM | Create* / Open* / SDK 内部初始化失败、二次故障 |
| 容易潜伏的位置 | 缓存、持有引用、忘记释放 | create/open 与 close/dispose 的不对称 |
| 表现形式 | 内存缓慢增加 | handle count 缓慢增加且不回落 |
因此,在长时间运行的排查中,「只看内存」很容易变成只用一只眼睛在观察。
至少把 Handle Count 和 Thread Count 放在一起看,会大大提升排查效率。
3. 案例:工业相机控制应用在 1 个月后突然崩溃
3.1. 出现的症状
现象本身很简单。
- 用于控制工业相机的 Windows 应用以 24/7 方式运行
- 平时运行一切正常
- 大约经过 1 个月左右,某天应用突然崩溃
- 重启之后,又可以正常运行一段时间
首先令人头疼的是,「崩溃之前的时间太长」。 每次再现都要等 1 个月,作为排查手段来说相当吃力。
更麻烦的是,崩溃的位置每次都不完全一样。 有时发生在重新连接开始之后,有时发生在开始采集时,有时发生在 SDK 调用失败之后。
看到这种现象,一开始可以怀疑的方向有很多:
- 相机 SDK 本身不稳定
- 通信或设备断开引起的临时故障
- 内存泄漏
- 与线程相关的 race
- 日志中没有体现的初始化失败
也就是说,一开始处于 「隐约觉得可疑的东西太多」 的状态。
3.2. 最先查看的指标
因此最先做的事情,是观察整个 process 资源的增长方式。 在这次案例中,观测到的趋势大致如下。
| 指标 | 观测到的趋势 | 解读 |
|---|---|---|
Handle Count |
在 reconnect 或 timeout 之后逐渐增加,且不会回落 | 怀疑是 handle 泄漏 |
Private Bytes |
有增有减,但单调增加的斜率很弱 | 主犯未必是 heap |
Thread Count |
基本持平 | thread leak 的可能性较低 |
| 崩溃位置 | 每次略有不同 | 二次故障的可能性较高 |
到这一步,排查方向已经大幅收窄。 因为与其把它看作「1 个月后崩溃」,不如看作「在运行过程中一点点地泄漏了某些东西,结果导致 1 个月后崩溃」,这样理解更自然。
3.3. 真正的泄漏位置
最终确认的原因是:相机重新连接时的初始化失败路径中创建的 event handle 没有被 close。
把流程简化之后,大致是这样:
sequenceDiagram
participant App as 控制应用
participant OS as Windows
participant SDK as 相机SDK
App->>OS: CreateEvent
App->>SDK: 注册 callback
SDK-->>App: 中途失败 / timeout
Note over App: 在 failure path 中 return
Note over App: 没有调用 CloseHandle
loop 多次 reconnect
App->>OS: Handle Count 逐渐增加
end
App->>OS: 下一次 CreateEvent / Open
OS-->>App: 失败
App-->>App: 作为二次故障崩溃
用代码来表示,大致是这样的泄漏:
handle = CreateEvent(...)
if (!RegisterCallback(handle))
{
return Error; // 漏掉了 CloseHandle(handle)
}
if (!StartAcquisition())
{
return Error; // 这里也漏掉了 close
}
...
CloseHandle(handle)
为什么在短时间测试中容易被忽略,理由也相当清楚:
- 正常启动 -> 正常结束的路径中会被 close
- 只有在 reconnect 中途才会失败
- 没有大量触发那条 failure path 的测试
- 在生产环境中会经过数周慢慢累积
也就是说,这是一种 「只看正常路径根本发现不了,但在异常路径中就是很平常地在泄漏」 的结构。
修复方案并不炫技:
- 让
create/open与close/dispose的职责更加靠近 - 把资源释放交给
finally/ destructor / session object,确保中途失败时也一定会释放 - 在 callback 注册、开始采集的前后明确 ownership
- 用代码的职责本身来表达「谁来关闭」,而不是靠注释
这里不算什么特别的技巧,更多的是把资源生命周期直接嵌入到代码结构中的整理工作。
4. 如何排查
4.1. 不等待以月为单位的再现,先压缩时间
在这类调查中,每次都等 1 个月才能再现,是一种效率很差的做法。 应该做的是 在短时间内反复走那条可疑的路径。
在这次案例中,通过运行下面这样的循环来压缩再现时间:
flowchart LR
A[启动] --> B[相机 open]
B --> C[开始采集]
C --> D[模拟 timeout / 断开]
D --> E[重新连接]
E --> F[恢复采集]
F --> G{是否重复 N 次}
G -- 是 --> D
G -- 否 --> H[确认结束时的差值]
关键在于,不是把时间花在正常「正在采集」的时间段上,而是花在边界处的生命周期操作上。
具体来说,以下几种场景比较有效:
- 大量循环执行
open -> start -> stop -> close - 故意触发 timeout 来反复执行 reconnect
- 在 callback 注册之后立刻让其失败
- 加入断线中断、重连中断、shutdown 竞争等情况
不需要完美再现 1 个月的实际运行情况。 相反,把怀疑的 lifetime edge 踩上几千次,反而离真正的原因更近。
4.2. 用 Handle Count 的斜率来看
在 handle 泄漏的排查中,只看绝对值有时很难判断问题所在。 重要的是 该回落的操作之后是否真的回落了,以及 多少次操作会增加多少个。
大致按下面的顺序来看会比较容易理解:
- 先确定预热之后的 baseline
- 在 reconnect / start-stop / close 之后记录
Handle Count - 查看每个循环的差值
- 再查看多个循环合计后的斜率
举例来说,可以用这样的方式来看:
leakSlope =
(currentHandleCount - baselineHandleCount)
/ reconnectCount
绝对值 2000 算多还是算少,取决于具体应用,会有很大差异。 但如果 每 reconnect 一次就 +1 且不会回落,那就相当可疑了。
这里的技巧是,不要只单独看 Handle Count,至少还要同时记录以下内容:
Handle CountPrivate BytesThread CountReconnectCount- 当前处于哪个 phase
这样就能比较快地判断出「是内存在增加」「是线程在增加」还是「每次重新连接资源都没有回落」。
4.3. 查看 create/open 与 close/dispose 的对应关系
即使确认整个 process 的 Handle Count 有问题,光靠这一点也无法定位到具体的泄漏位置。
接下来需要的是 能够成对查看资源生命周期的日志。
大致的形式类似下面这种 structured log:
CameraSession session=421 cameraId=CAM01 phase=ReconnectStart reason=FrameTimeout handleCount=1824 privateBytesMB=418
CameraResource session=421 resourceId=evt-884 kind=Event name=FrameReady action=Create osHandle=0x00000ABC handleCount=1825
CameraResource session=421 resourceId=evt-884 kind=Event name=FrameReady action=Close osHandle=0x00000ABC handleCount=1824
这里重要的一点是,不要只依赖 osHandle。
Windows 的 handle 值之后可能会被重复利用,所以日志中至少应该带上以下字段,才更容易追踪:
sessionIdresourceIdkindaction(Create/Open/Register/Close/Dispose/Unregister)osHandlephase
这样一来,就更容易发现 「有 Create 却没有 Close」 这种只有一半流程的情况。
4.4. handle 泄漏要找的不是「崩溃的位置」而是「泄漏的位置」
这一点相当重要。
handle 泄漏经常会呈现出这样的形态:
- 崩溃发生的那一行:
CreateEvent失败 - 真正的泄漏:数天前起,failure path 中就一直漏掉了
CloseHandle
也就是说,最后崩溃的那个 API 只是 受害的出口,未必是 原因的入口。
因此,排查的顺序应该是:
- 先看哪个资源在持续增加
- 再看在哪个操作边界没有回落
- 找出
create/open与close/dispose配对被破坏的位置 - 最后才去读崩溃发生的位置
按这个顺序排查,会大幅降低迷路的可能性。
5. 为防止再次发生所需的日志
5.1. 首先应保留的最小集合
这次调查真正起作用的,并不是单纯增加日志的数量。 而是整理并增加 「事后能够追溯到原因的信息」。
至少应该保留以下这些内容:
| 分类 | 最低限度需要的字段 | 理由 |
|---|---|---|
| 操作上下文 | cameraId、sessionId、operationId、reconnectCount、phase |
用于关联「发生在哪个操作的第几次」 |
| process 资源 | handleCount、privateBytes、workingSet、threadCount |
先分辨清楚到底是什么在增加 |
| resource lifecycle | action、resourceId、kind、osHandle、owner |
追踪 create/open 与 close/dispose 的配对 |
| 外部调用结果 | win32Error、HRESULT、sdkError、timeoutMs |
便于事后比较失败的类型 |
| 状态迁移 | OpenStart、OpenDone、ReconnectStart、ReconnectDone、ShutdownStart 等 |
用于了解在哪个 phase 的中途出现问题 |
| 运行环境 | pid、tid、buildVersion、machineName |
便于与 dump / symbol / 发布版本对应起来 |
这并不能说是完备的方案。 但如果连这些都没有,日志很容易就只剩下 「崩溃了」这个事实本身。
5.2. 实际强化的日志
在这次案例中,日志按以下方向进行了强化。
- 定期 heartbeat
- 每隔 1〜5 分钟输出一次
Handle Count/Private Bytes/Thread Count/ReconnectCount
- 每隔 1〜5 分钟输出一次
- 以相机 session 为单位的边界日志
OpenStartCallbackRegisteredAcquisitionStartTimeoutDetectedReconnectStartReconnectDoneCloseStartCloseDone
- 资源生命周期日志
- event / thread / file / timer / SDK registration token 的
Create/Open/Register与Close/Dispose/Unregister
- event / thread / file / timer / SDK registration token 的
- 错误的规范化
- 不只是留下异常 message,同时输出
win32Error、HRESULT、sdkError、phase
- 不只是留下异常 message,同时输出
重要的是,成功和失败时都不要改变日志的格式。 如果只在异常时改用另一种格式,事后统计分析会变得很麻烦。
5.3. 该以什么粒度采集
这里容易犯的一个错误是「先全部用 INFO 级别输出」。 但这样做的话,事后阅读日志时会形成一堵「日志墙」,读起来相当痛苦。
在粒度上,比较现实的划分大致是这样:
- 定期监控
Handle Count、Private Bytes、Thread Count、ReconnectCount
- 操作边界
- session 的 start / done / fail
- 资源边界
create/open/register与close/dispose/unregister
- 异常时的详细信息
- error code、stack、dump 采集触发条件
通常不需要每一帧都输出详细日志。 相反,能读出 「哪个职责打开了资源,哪个职责关闭了资源」 的日志,对长时间运行的故障排查更有帮助。
6. 大致的使用区分
- 只在数天〜数周之后才崩溃
- 先加入
Handle Count/Private Bytes/Thread Count的 heartbeat
- 先加入
- 存在 retry / reconnect / shutdown
- 先做一个只针对这些边界大量循环的 harness
- 大量使用 native SDK / P/Invoke / Win32
- 使用下篇提到的 Application Verifier 的价值很高
- 同时带有 GUI
- 除了
Handle Count,还应该看GDI Objects/USER Objects
- 除了
- 仅凭崩溃瞬间的异常什么都看不出来
- 先整理好 operation / session / resource lifecycle 的 structured log 会更快
最后一项相当重要。 在故障排查中,胜负往往不取决于分析技术本身,而是取决于 是否已经把系统变成了可观测的形式。
7. 总结
对于只在长时间运行后才崩溃的应用,不能只看内存,还要看 Handle Count。handle 泄漏往往不藏在正常路径中,而是潜伏在异常路径的 failure path 里,崩溃发生的位置通常不是泄漏发生的地方,而是二次故障的出口。归根结底,症状的解读方式就是这 3 点。
在防止再次发生方面,应该让 create/open 与 close/dispose 的职责更加靠近,以 session / operation 为单位保留带有上下文的日志,同时记录 process 资源与 resource lifecycle 两方面的信息。在测试上,不等待以月为单位的再现,而是用短循环反复执行 timeout / reconnect / shutdown,把合格标准设定为不仅「不会崩溃」,还要「崩溃时能够追溯原因」。这次真正起作用的,就是这样的组合。下篇会使用 Application Verifier,把内存不足或 handle 异常这类不容易出现的破坏方式提前逼出来。
对于控制类应用,正常路径能跑通固然重要, 但 崩溃时能够「知道发生了什么」 在长期运行中往往更加关键。
handle 泄漏正是这种差异能够发挥作用的典型故障类型。 不要只在发生的瞬间去看,而是从增长方式、边界、职责配对这几个角度去看,会大大提升排查效率。
下篇:工业相机控制应用运行一个月后突然崩溃时(下篇) - 什么是 Application Verifier 与异常路径测试基础设施的做法
8. 参考资料
相关文章
共享相同标签的最新文章。可以围绕相近的主题进一步加深理解。
工业相机控制应用运行一个月后突然崩溃时(下篇) - 什么是 Application Verifier 与异常路径测试基础设施的做法
下篇整理 Application Verifier 是什么以及怎么把它编入 Windows 异常路径测试基础设施。用 Handles 抓 invalid handle、Low Resource Simulation 不用把机器榨干就触发资源不足,搭配 harness EXE...
Windows 事件日志・ETW 入门 ── 让业务应用程序的日志接入操作系统标准机制
Windows 业务应用程序的日志,是不是只靠文件日志来解决?事件日志与 ETW,是运维人员和操作系统标准工具所能看到的另一层记录。本文整理三种手段的分工方式、.NET 中的写入方法、通过 EventSource 进行的 ETW 埋点、收集与排查的实务做法,以及来源未注册、...
委托开发 Windows 应用程序前该梳理的事项
在委托外包开发 Windows 应用程序之前,梳理现有软件改造、设备联动、COM/ActiveX、发布与更新、维护等需要注意的要点。
TCP 重传导致工业相机通信中断的原因与排查
本文整理当 TCP 重传导致工业相机通信中断数秒时的排查方法,结合丢包、RTO、RFC1323 时间戳、Wireshark 确认要点一并说明。
用 PerfView 与 dotnet-trace 定位“变慢”的原因 ── .NET 性能排查实务入门
当业务应用出现“变慢”“CPU 占满”“偶尔卡死”时,该用哪个工具看什么?本文梳理 PerfView 与 dotnet-trace 的分工、CPU 采样的解读方法(inclusive/exclusive)、用 ThreadTime 排查阻塞时间,以及与 EventSourc...
常见问题
汇总了咨询这一主题时常见的问题。
- 什么是 handle 泄漏?
- handle 泄漏是指 Windows 进程忘记关闭用于引用 event、mutex、file、socket 等 OS 资源的 handle,导致 Handle Count 持续增加的现象。尤其常见的模式是:为某个操作临时打开的资源,在 timeout、reconnect、early return 等中途失败的路径上忘记关闭,而平时的短时间测试大多只会走成功路径,因此很容易被忽略。
- 内存泄漏和 handle 泄漏该如何区分?
- 两者要看的指标不同。内存泄漏表现为 Private Bytes 或 Commit 持续缓慢增加,而 handle 泄漏表现为 Handle Count 持续缓慢增加且不会回落。在长时间运行的排查中,如果只看内存,很容易变成「只用一只眼睛在观察」,因此基本原则是把 Handle Count 和 Thread Count 一起看。如果应用还带有 GUI,还要同时关注 GDI Objects / USER Objects。
- 为什么有 handle 泄漏时,只有长时间运行后才会崩溃?
- 因为每次失败只泄漏一个的这种小斜率泄漏,在几分钟内不会有任何异常,但在 24/7 运行的场景下,timeout、重新连接等边界条件会反复发生,经过数周不断累积。最终会在创建新的 event/file/thread 的 API 调用失败时,以二次故障的形式表现出来。还有一个重点是:崩溃发生的位置往往不是泄漏发生的地方,而是最后的受害者。
- handle 泄漏应该如何排查?
- 不要等待以月为单位的再现,而是把 open -> start -> stop -> close,以及 timeout、reconnect 这类可疑的生命周期操作边界,放进短循环里跑上几千次,压缩再现所需的时间。先确定预热之后的 baseline,观察 Handle Count 每个循环的差值与斜率,再用带有 sessionId、resourceId、action 的 structured log 找出 create/open 与 close/dispose 对应关系被破坏的位置,最后才去读崩溃发生的位置——按这个顺序排查,比较不容易迷路。
作者简介
本文作者的个人简介页面。
Go Komura
小村软件有限公司 代表
以 Windows 软件开发、技术咨询与故障排查为中心,擅长难以复现的故障调查,以及既有资产仍在运行的项目。