使用循环收集器日志调试“泄漏直至关闭”问题

这是一个如何使用循环收集器日志来理解可能导致“泄漏直至关闭”问题的原因的示例。

简介

首先,我的意思是?Firefox 中有很多不同的泄漏检查器。我们正在讨论的那个有如下所示的错误

TEST_END: FAIL, expected PASS - leaked 1 window(s) until shutdown [url = chrome://browser/content/browser.xhtml]

除了“window”之外,这里还可以出现其他内容,例如 docshell。重要的是“until shutdown”。这意味着在特定测试期间创建了一个窗口,但在我们完成测试后没有立即销毁它。但是,在我们关闭整个浏览器时,它已被销毁。这通常意味着 chrome JS 在某个全局变量中存储了对窗口的引用,并在测试消失之前忘记清除它。在最坏的情况下,这可能意味着 chrome JS 泄漏了我们打开的每个网页。这种泄漏不会被我们的其他泄漏检查器检测到,因为它们在关闭时运行,并且在我们关闭之前所有 chrome JS 都被清除了。

初步调查

现在您希望更好地理解此泄漏的含义,我们可以讨论调查应如何进行。首先,您希望获取有关哪个测试创建了泄漏窗口的更多信息,以便您可以弄清楚如何在不运行大量测试的情况下重现泄漏。

信息出现在我上面显示的那一行之前,如下所示

INFO TEST-INFO | browser/components/sessionstore/test/browser_tab_groups_empty.js | windows(s) leaked: [pid = 6245] [serial = 12], [pid = 6245] [serial = 13]
TEST_END: FAIL, expected PASS - leaked 1 window(s) until shutdown [url = chrome://browser/content/browser.xhtml]

这意味着在运行测试 browser_tab_groups_empty.js 时创建了窗口。这两个窗口由字符串 [pid = 6245] [serial = 12][pid = 6245] [serial = 13] 唯一标识。您可以在测试日志中搜索以查看这些窗口创建或销毁的确切时刻,这可能很有用。

例如,这是创建第一个窗口的位置

GECKO(6245) [Parent 6245: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (198390000) [pid = 6245] [serial = 12] [outer = 0]

窗口被销毁的位置看起来类似,只是它将具有 --DOMWINDOW 而不是 ++DOMWINDOW

在我们深入分析循环收集器日志的复杂性之前,这是一个花几分钟时间回顾您的补丁并查看您是否可以弄清楚在何处可能创建了对窗口的强引用,而未在关闭窗口时清除它。对于一个小补丁,通过推理而不是使用循环收集器日志来弄清楚它可能会更容易。

获取循环收集器日志

如果这不起作用,我们可以看看创建和分析循环收集器日志。

您要做的第一件事是确定泄漏是在父进程中还是在子进程中,以便我们可以创建更少的无用日志。在上面的示例中,++DOMWINDOW 的日志记录显示 [Parent 6245: Main Thread],因此我们可以确定它位于父进程中。它也可以显示为 [Child 6246: Main Thread],这意味着它位于子进程中。

您要做的第二件事是确保您可以在单独运行时重现泄漏。有时测试之间存在奇怪的交互,因此我们希望检查这里是否不是这种情况。虽然不需要调试构建来获取循环收集器日志,但如果您尝试修复的错误仅在调试构建中显示,则也需要使用调试构建。

对于我们的示例测试,您可以运行以下命令来确认错误

./mach test --headless browser_tab_groups_empty.js

确认后,我们需要使用许多环境变量设置重新运行测试,以便捕获一些日志。它看起来像这样

MOZ_DISABLE_CONTENT_SANDBOX=t MOZ_CC_LOG_DIRECTORY=~/logs/emptylog/ MOZ_CC_LOG_ALL=1 MOZ_CC_LOG_PROCESS=main MOZ_CC_LOG_THREAD=main ./mach test --headless browser_tab_groups_empty.js

分解

  1. MOZ_DISABLE_CONTENT_SANDBOX=t 禁用沙箱,以便内容进程可以将日志保存到磁盘。如果您只记录父进程,则不需要此操作。

  2. MOZ_CC_LOG_DIRECTORY=~/logs/emptylog/ 设置我们保存日志到的目录。根据需要进行调整。该目录必须已存在。

  3. MOZ_CC_LOG_ALL=1 在浏览器运行期间记录每个循环收集。我们必须这样做,因为我们无法预先知道哪个 CC 会捕获窗口泄漏时的状态。这意味着我们将有许多日志。

  4. MOZ_CC_LOG_PROCESS=main 只记录主进程的日志。如果您之前确定泄漏在父进程中,则需要这样做。如果您确定泄漏在子进程中,则右侧将为 content 而不是 main。这样做是为了减少您需要筛选的日志数量,以及避免通过更改时间来隐藏泄漏(日志记录可能很慢)。

  5. MOZ_CC_LOG_THREAD=main 只记录主线程的日志,忽略工作线程上的 CC。此泄漏检查器关心的所有内容都仅限于主线程,因此它将始终如此。与前一个一样,这里的目标是减少我们生成的日志数量。

有许多不同的方法可以运行循环收集器,包括在 try 上运行,但我们在这里不做介绍。

现在运行测试以获取日志。除了循环收集器日志外,您还需要保留正常测试日志的副本。

分析日志

在捕获循环收集器日志的运行的测试日志中,我们将查找与初始泄漏日志中相同的信息。首先,我们希望了解哪些窗口泄漏了

INFO TEST-INFO | browser/components/sessionstore/test/browser_tab_groups_empty.js | windows(s) leaked: [pid = 90804] [serial = 12], [pid = 90804] [serial = 13]

这告诉我们具有泄漏窗口的进程的 PID 为 90804。

现在在测试日志中查找这些泄漏窗口的信息

GECKO(90804) [Parent 90804: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (135153800) [pid = 90804] [serial = 12] [outer = 0] [url = chrome://browser/content/browser.xhtml]
GECKO(90804) [Parent 90804: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (14b22fc00) [pid = 90804] [serial = 13] [outer = 0] [url = about:blank]

这告诉我们 0x135153800 和 0x14b22fc00 是相关窗口的地址。现在,让我们关注窗口 0x135153800。一个是内部,一个是外部,因此如果我们修复了一个泄漏,我们可能会同时修复它们。

现在我们转到保存 CC 日志的目录,并查看哪些日志具有我们感兴趣的窗口,使用我们刚刚收集的有关 PID 和地址的信息

~/logs/emptylog % grep nsGlobalWindow cc-edges.90804* | grep 135153800
cc-edges.90804-1.log:0x135153800 [rc=2] nsGlobalWindowOuter # 30 outer
cc-edges.90804-2.log:0x135153800 [rc=2] nsGlobalWindowOuter # 30 outer
cc-edges.90804-3.log:0x135153800 [rc=2] nsGlobalWindowOuter # 30 outer
cc-edges.90804-4.log:0x135153800 [rc=2] nsGlobalWindowOuter # 30 outer
cc-edges.90804-5.log:0x135153800 [rc=2] nsGlobalWindowOuter # 30 outer
cc-edges.90804-6.log:0x135153800 [rc=2] nsGlobalWindowOuter # 30 outer
cc-edges.90804-7.log:0x135153800 [rc=2] nsGlobalWindowOuter # 30 outer

文件名中的数字表示这些日志创建的顺序。cc-edges.90804-7.log 是窗口最后出现的日志,因此这可能是 CC 窗口被释放的日志。我们可以通过在日志中查找特殊的 [garbage] 指示符来确认这一点

~/logs/emptylog % grep 0x135153800 cc-edges.90804* | grep garbage
cc-edges.90804-7.log:0x135153800 [garbage]

因为窗口在日志 7 中被清理,所以我们要调查日志 6,因为窗口仍然存在,但可能应该已经被清理了。(泄漏检查框架在窗口应该被清理的点之前运行了许多 CC。)为此,我们需要 find_roots 脚本 来自这里。您向此脚本提供日志的名称和对象的地址

~/logs/emptylog % ~/tools/heapgraph/find_roots.py cc-edges.90804-6.log 0x14b22fc00
Parsing cc-edges.90804-6.log. Done loading graph.

0x135df8640 [LoadedScript]
    --[mModuleRecord]--> 0x2cf45673da80 [JS Object (Module)]
    --[**UNKNOWN SLOT 1**]--> 0x2cf45673dad8 [JS Object (ModuleEnvironmentObject)]
    --[SessionStoreTestUtils]--> 0x39112798e660 [JS Object (Object)]
    --[windowGlobal]--> 0x2cf45676e660 [JS Object (Proxy)]
    --[baseshape_global, proxy target]--> 0x112cd36e8c90 [JS Object (Window)]
    --[UnwrapDOMObject(obj)]--> 0x14b22fc00 [nsGlobalWindowInner # 31 inner chrome://browser/content/browser.xhtml]

    Root 0x135df8640 is a ref counted object with 1 unknown edge(s).
    known edges:
        0x2cf45676e5f0 [JS Object (ScriptSource)]  --[]--> 0x135df8640

此 ASCII 艺术表示从 LoadedScript 对象到窗口存在一条路径。

--[mModuleRecord]--> 是此路径中的边,标签为 mModuleRecord

在这种特定情况下,SessionStoreTestUtils 对象在测试关闭后仍然持有对窗口的引用似乎很可疑,并且调查泄漏的人员更改了测试以避免使用 SessionStoreTestUtils