工业相机长期运行崩溃调查 - handle 泄漏篇

· · Windows 开发, 故障排查, 工业相机, handle 泄漏, 日志设计

当 Windows 应用在长时间运行后突然崩溃时,很多人第一反应都会怀疑是内存泄漏。 不过实际上,handle 泄漏 才是真正的元凶,直到数周之后才以二次故障的形式浮出水面,这样的案例也不少见。

本文要介绍的是一个真实案例:某个用于控制工业相机的 Windows 应用,在连续运行约 1 个月之后突然崩溃。经过排查,最终确认原因是 相机重新连接相关失败路径中发生的 handle 泄漏

上篇整理 handle 泄漏是什么、这次事件是如何排查的,以及为了防止再次发生应该保留哪些日志。 下篇会在 工业相机控制应用运行一个月后突然崩溃时(下篇) - 什么是 Application Verifier 与异常路径测试基础设施的做法 中,介绍异常路径测试基础设施的内容。

文中隐去了一些专有名词和部分日志字段,但这里的思路本身,在 Windows 设备控制类应用中具有相当高的通用性。

目录

  1. 先说结论(一句话)
  2. 什么是 handle 泄漏
    • 2.1. 这里所说的「handle」
    • 2.2. 为什么只有长时间运行后才会表面化
    • 2.3. 与内存泄漏的区别
  3. 案例:工业相机控制应用在 1 个月后突然崩溃
    • 3.1. 出现的症状
    • 3.2. 最先查看的指标
    • 3.3. 真正的泄漏位置
  4. 如何排查
    • 4.1. 不等待以月为单位的再现,先压缩时间
    • 4.2. 用 Handle Count 的斜率来看
    • 4.3. 查看 create/openclose/dispose 的对应关系
    • 4.4. handle 泄漏要找的不是「崩溃的位置」而是「泄漏的位置」
  5. 为防止再次发生所需的日志
    • 5.1. 首先应保留的最小集合
    • 5.2. 实际强化的日志
    • 5.3. 该以什么粒度采集
  6. 大致的使用区分
  7. 总结
  8. 参考资料

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 泄漏未必会在一次失败中就轰然崩溃。 更麻烦的其实是 每次失败只泄漏一个 这种斜率很小的泄漏。

正常运行偶尔出现 timeout / reconnect在失败路径中创建 Event Handle没有调用 CloseHandleHandle Count 略微增加重复几百次CreateEvent / SDK open 失败在别的地方崩溃 / 停止

如果每次 reconnect 只泄漏一个,几分钟内什么都不会发生。 但是,在 24/7 运行的设备控制应用中,timeout、重新初始化、断线恢复这类边界条件会反复出现。 结果就变成了一种奇怪的现象:只有在数周之后才会表面化。

这里重要的一点是:handle 泄漏本身未必就是崩溃的那一行。 更常见的破坏方式是这样的:

  • 创建新 event / file / thread 的 API 调用失败
  • SDK 内部无法创建所需的资源,只返回一个通用的失败代码
  • 失败后的错误处理比较薄弱,踩到 null / invalid handle 而崩溃
  • timeout 增多,结果被 watchdog 或上层控制逻辑 kill 掉

也就是说,崩溃发生的位置是「最后的受害者」,未必是「最初的犯人」。

2.3. 与内存泄漏的区别

长时间运行后出现的故障,第一反应通常是怀疑内存泄漏。 这种反应本身很自然,但 handle 泄漏往往需要从另一个维度去看,才能更快找到问题。

视角 内存泄漏 handle 泄漏
最先看的指标 Private BytesCommitWorking Set Handle Count
典型症状 内存紧张、paging、变慢、OOM Create* / Open* / SDK 内部初始化失败、二次故障
容易潜伏的位置 缓存、持有引用、忘记释放 create/openclose/dispose 的不对称
表现形式 内存缓慢增加 handle count 缓慢增加且不回落

因此,在长时间运行的排查中,「只看内存」很容易变成只用一只眼睛在观察。 至少把 Handle CountThread 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

把流程简化之后,大致是这样:

相机SDKWindows控制应用相机SDKWindows控制应用在 failure path 中 return没有调用 CloseHandleloop[多次 reconnect]CreateEvent注册 callback中途失败 / timeoutHandle Count 逐渐增加下一次 CreateEvent / Open失败作为二次故障崩溃

用代码来表示,大致是这样的泄漏:

handle = CreateEvent(...)

if (!RegisterCallback(handle))
{
    return Error;   // 漏掉了 CloseHandle(handle)
}

if (!StartAcquisition())
{
    return Error;   // 这里也漏掉了 close
}

...
CloseHandle(handle)

为什么在短时间测试中容易被忽略,理由也相当清楚:

  • 正常启动 -> 正常结束的路径中会被 close
  • 只有在 reconnect 中途才会失败
  • 没有大量触发那条 failure path 的测试
  • 在生产环境中会经过数周慢慢累积

也就是说,这是一种 「只看正常路径根本发现不了,但在异常路径中就是很平常地在泄漏」 的结构。

修复方案并不炫技:

  • create/openclose/dispose 的职责更加靠近
  • 把资源释放交给 finally / destructor / session object,确保中途失败时也一定会释放
  • 在 callback 注册、开始采集的前后明确 ownership
  • 用代码的职责本身来表达「谁来关闭」,而不是靠注释

这里不算什么特别的技巧,更多的是把资源生命周期直接嵌入到代码结构中的整理工作。

4. 如何排查

4.1. 不等待以月为单位的再现,先压缩时间

在这类调查中,每次都等 1 个月才能再现,是一种效率很差的做法。 应该做的是 在短时间内反复走那条可疑的路径

在这次案例中,通过运行下面这样的循环来压缩再现时间:

启动相机 open开始采集模拟 timeout / 断开重新连接恢复采集是否重复 N 次确认结束时的差值

关键在于,不是把时间花在正常「正在采集」的时间段上,而是花在边界处的生命周期操作上

具体来说,以下几种场景比较有效:

  • 大量循环执行 open -> start -> stop -> close
  • 故意触发 timeout 来反复执行 reconnect
  • 在 callback 注册之后立刻让其失败
  • 加入断线中断、重连中断、shutdown 竞争等情况

不需要完美再现 1 个月的实际运行情况。 相反,把怀疑的 lifetime edge 踩上几千次,反而离真正的原因更近。

4.2. 用 Handle Count 的斜率来看

在 handle 泄漏的排查中,只看绝对值有时很难判断问题所在。 重要的是 该回落的操作之后是否真的回落了,以及 多少次操作会增加多少个

大致按下面的顺序来看会比较容易理解:

  1. 先确定预热之后的 baseline
  2. 在 reconnect / start-stop / close 之后记录 Handle Count
  3. 查看每个循环的差值
  4. 再查看多个循环合计后的斜率

举例来说,可以用这样的方式来看:

leakSlope =
    (currentHandleCount - baselineHandleCount)
    / reconnectCount

绝对值 2000 算多还是算少,取决于具体应用,会有很大差异。 但如果 每 reconnect 一次就 +1 且不会回落,那就相当可疑了。

这里的技巧是,不要只单独看 Handle Count,至少还要同时记录以下内容:

  • Handle Count
  • Private Bytes
  • Thread Count
  • ReconnectCount
  • 当前处于哪个 phase

这样就能比较快地判断出「是内存在增加」「是线程在增加」还是「每次重新连接资源都没有回落」。

4.3. 查看 create/openclose/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 值之后可能会被重复利用,所以日志中至少应该带上以下字段,才更容易追踪:

  • sessionId
  • resourceId
  • kind
  • action(Create/Open/Register/Close/Dispose/Unregister)
  • osHandle
  • phase

这样一来,就更容易发现 「有 Create 却没有 Close」 这种只有一半流程的情况。

4.4. handle 泄漏要找的不是「崩溃的位置」而是「泄漏的位置」

这一点相当重要。

handle 泄漏经常会呈现出这样的形态:

  • 崩溃发生的那一行:CreateEvent 失败
  • 真正的泄漏:数天前起,failure path 中就一直漏掉了 CloseHandle

也就是说,最后崩溃的那个 API 只是 受害的出口,未必是 原因的入口

因此,排查的顺序应该是:

  1. 先看哪个资源在持续增加
  2. 再看在哪个操作边界没有回落
  3. 找出 create/openclose/dispose 配对被破坏的位置
  4. 最后才去读崩溃发生的位置

按这个顺序排查,会大幅降低迷路的可能性。

5. 为防止再次发生所需的日志

5.1. 首先应保留的最小集合

这次调查真正起作用的,并不是单纯增加日志的数量。 而是整理并增加 「事后能够追溯到原因的信息」

至少应该保留以下这些内容:

分类 最低限度需要的字段 理由
操作上下文 cameraIdsessionIdoperationIdreconnectCountphase 用于关联「发生在哪个操作的第几次」
process 资源 handleCountprivateBytesworkingSetthreadCount 先分辨清楚到底是什么在增加
resource lifecycle actionresourceIdkindosHandleowner 追踪 create/openclose/dispose 的配对
外部调用结果 win32ErrorHRESULTsdkErrortimeoutMs 便于事后比较失败的类型
状态迁移 OpenStartOpenDoneReconnectStartReconnectDoneShutdownStart 用于了解在哪个 phase 的中途出现问题
运行环境 pidtidbuildVersionmachineName 便于与 dump / symbol / 发布版本对应起来

这并不能说是完备的方案。 但如果连这些都没有,日志很容易就只剩下 「崩溃了」这个事实本身

5.2. 实际强化的日志

在这次案例中,日志按以下方向进行了强化。

  1. 定期 heartbeat
    • 每隔 1〜5 分钟输出一次 Handle Count / Private Bytes / Thread Count / ReconnectCount
  2. 以相机 session 为单位的边界日志
    • OpenStart
    • CallbackRegistered
    • AcquisitionStart
    • TimeoutDetected
    • ReconnectStart
    • ReconnectDone
    • CloseStart
    • CloseDone
  3. 资源生命周期日志
    • event / thread / file / timer / SDK registration token 的 Create/Open/RegisterClose/Dispose/Unregister
  4. 错误的规范化
    • 不只是留下异常 message,同时输出 win32ErrorHRESULTsdkErrorphase

重要的是,成功和失败时都不要改变日志的格式。 如果只在异常时改用另一种格式,事后统计分析会变得很麻烦。

5.3. 该以什么粒度采集

这里容易犯的一个错误是「先全部用 INFO 级别输出」。 但这样做的话,事后阅读日志时会形成一堵「日志墙」,读起来相当痛苦。

在粒度上,比较现实的划分大致是这样:

  • 定期监控
    • Handle CountPrivate BytesThread CountReconnectCount
  • 操作边界
    • session 的 start / done / fail
  • 资源边界
    • create/open/registerclose/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/openclose/dispose 的职责更加靠近,以 session / operation 为单位保留带有上下文的日志,同时记录 process 资源与 resource lifecycle 两方面的信息。在测试上,不等待以月为单位的再现,而是用短循环反复执行 timeout / reconnect / shutdown,把合格标准设定为不仅「不会崩溃」,还要「崩溃时能够追溯原因」。这次真正起作用的,就是这样的组合。下篇会使用 Application Verifier,把内存不足或 handle 异常这类不容易出现的破坏方式提前逼出来。

对于控制类应用,正常路径能跑通固然重要, 但 崩溃时能够「知道发生了什么」 在长期运行中往往更加关键。

handle 泄漏正是这种差异能够发挥作用的典型故障类型。 不要只在发生的瞬间去看,而是从增长方式、边界、职责配对这几个角度去看,会大大提升排查效率。

下篇:工业相机控制应用运行一个月后突然崩溃时(下篇) - 什么是 Application Verifier 与异常路径测试基础设施的做法

8. 参考资料

共享相同标签的最新文章。可以围绕相近的主题进一步加深理解。

常见问题

汇总了咨询这一主题时常见的问题。

什么是 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 软件开发、技术咨询与故障排查为中心,擅长难以复现的故障调查,以及既有资产仍在运行的项目。

返回博客列表