R·ex / Zeng


音游狗、安全狗、攻城狮、业余设计师、段子手、苦学日语的少年。 MUGer, hacker, developer, amateur UI designer, punster, Japanese learner.

追根究底:不打开 DevTools 时,console.log 会不会内存泄漏?

TL;DR:会。并且虽然 Chromium 有试图做限制,但因为方法不合适所以并没能解决问题。

JavaScript 的内存泄漏原因有很多,例如 DOM、计时器、闭包、意外的全局变量,以及本文的主题:console.log。关于 console.log 会不会造成内存泄漏,掘金上面有大佬发过两篇文章:

这两篇文章的结论是:在打开 DevTools 时一定有泄漏(文中的代码很显然可以证明),但如果没打开 DevTools,似乎就不会有问题了(文中 performance 的数据也可以证明)。

但我结合自己之前的经验,产生了一个疑惑:如果不会造成内存泄漏,说明对象被 GC 掉了,那我为什么在打开 DevTools 后还能看到打开之前 log 的对象呢?这些对象肯定被存到了一个地方,肯定还占据着内存。于是本着追根究底的精神,我决定通过实验、猜想、追踪代码求证等方式来得到答案。

可以复现的内存泄漏

其实在文章的评论区有人就指出:只要每次 log 的是不同的对象,不管是否打开 DevTools 都会内存溢出。我这里以一个长度为 1 M 的 number 数组为例,简单修改一下文中的代码:

const MB = 1024 * 1024;
function log() {
  const memory = performance.memory.totalJSHeapSize;
  const usagedMemory = Math.floor(memory / MB);
  box.insertAdjacentHTML('beforeend', `<span>${usagedMemory} </span>`);
  const obj = {
    usagedMemory,
    str: Array(1 * MB).fill(0).map(() => Math.random()),
  };
  console.log(obj.str);
  setTimeout(() => log(), 50);
}
log();

本来我是打算用操作系统的任务管理器来查看内存占用的,但为了避免其它进程以及操作系统的内存压缩、虚拟内存的影响,我最终打开了 Chrome 自己的任务管理器。

可以看出,页面上输出的 usagedMemory 始终是 9,但 Chrome 的任务管理器里面这个 Tab 的内存占用却一直在往上涨,直到用到 3.4~3.6 GB 时页面崩溃。之后我关掉任务管理器重试,页面依旧会崩溃,所以一定是因为“超过了内存限制”,而不是“任务管理器的观测会造成内存泄漏”。

test.html 耗费了 3.4 GB 内存

即使不开 DevTools 页面也会崩溃

光是凭借这个例子就足以证明,即使不打开 DevTools 也会造成内存泄漏。并且可以发现 console.log 打印的数据并不在 performance.memory.totalJSHeapSize 的管辖范围内。那它们去了哪里呢?我把目光看向了 Chromium 的源代码。

静态代码追踪

作为一个对速度要求极高的程序,Chromium 的大部分内容(包括 v8)是用 C++ 写的。追踪代码首先要能看到代码,虽然我可以将仓库 clone 下来本地追踪,但其项目过大,clone 需要一些时间,且会对我的 IDE 造成不小的压力。一个更好的方法是通过官方提供的 Chromium Code Search 页面来搜索代码、跟踪跳转。

一开始,我试图在 The Chromium Projects 页面寻找项目结构相关的文档,目的是直接找到 console API 所在的目录,但无果,因此只能直接搜索代码。考虑到 console.log 可能会被转化为看似完全不相干的 C++ 函数调用,且这个函数调用过于通用,可能会搜到很多文档注释相关的东西,于是我转而去搜索 console info,因为按照经验它一定会跟 console.log 的实现在同一个模块下,并且它并不经常出现。

运气不错,第一个结果看起来就很接近目标了:

第一个结果就可能是我想要的

文件是 v8/src/inspector/v8-console.h,按照 C++ 的项目规范,.h 文件一般只有 declaration 而不是 implementation(网站里叫 definition),因此先点进去,然后依次单击代码中的 Log 符号、弹出窗口中唯一一条 Definition 结果,右边新的弹窗就是我们要找的函数了,如下图所示。

追代码的过程

这只是第一步,顺着这个思路,可以追踪到 reportCall,然后是 V8ConsoleMessageStorage::addMessage 方法,在函数的结尾将参数 message 追加到了一个 vector(C++ STL 提供的可变长度的数组)的末尾(传送门):

m_messages.push_back(std::move(message));

至于 m_messages,则是 V8ConsoleMessageStorage 这个 class 的一个成员变量,而这个 class 的实例是跟着 v8 isolates 走的,并且只有用到的时候才创建,例如调用 console.log 时。关于什么是 v8 isolates,Cloudflare 有一段 很好的解释

V8 orchestrates isolates: lightweight contexts that provide your code with variables it can access and a safe environment to be executed within. You could even consider an isolate a sandbox for your function to run in.
V8 引擎将 isolate 作为轻量级的上下文,为你的代码提供变量访问和安全的执行环境。你甚至可以将 isolate 视为你的函数运行的沙盒。

原来是存在了 v8 相关的实例里面,那 performance API 拿不到似乎也情有可原了。

Chromium 中失效的限制

值的留意的是,刚刚追踪到的代码在 push_back 之前其实有一个小判断:

DCHECK(m_messages.size() <= maxConsoleMessageCount);
if (m_messages.size() == maxConsoleMessageCount) {
  m_estimatedSize -= m_messages.front()->estimatedSize();
  m_messages.pop_front();
}
while (m_estimatedSize + message->estimatedSize() > maxConsoleMessageV8Size &&
      !m_messages.empty()) {
  m_estimatedSize -= m_messages.front()->estimatedSize();
  m_messages.pop_front();
}

可以看出,Chromium 对 m_messages 可以存放的总预估体积(estimateSize,可能不准确)做了限制,如果超出了这个限制,最早放入 m_messages 中的消息将被删除。这个限制的定义是 maxConsoleMessageV8Size = 10 * 1024 * 1024,也就是……10 MB??

这个值我觉得过于小了,我们的测试代码每 50 ms 会产生至少 1 MB 内存,即使预估再不准确,应该也很快就会超过这个限制才对。难道是限制失效了?但通过静态分析代码我已经没有太多头绪了,说不定动态调试可以帮我了解更多的细节。

动态调试

四年前我有个机会自己编译并简单(通过输出日志的方式)调试了 Chromium 项目(文章传送门),凭借着那次经历,我决定再试一次。

编译 Chromium(再次)

由于年代久远,我又一次打开了 The Chromium Projects 的指南。不同的是这次我没有在 Ubuntu 虚拟机上搞,而是直接用了 Mac 系统,因此需要查看 Mac 对应的文档:Checking out and building Chromium for Mac。关键的几步是:

# 1. 安装完整版的 Xcode,注意不能是命令行版的。如果此命令可以正常输出则表示安装完成:
ls `xcode-select -p`/Platforms/MacOSX.platform/Developer/SDKs

# 2. 安装官方工具集 `depot_tools`,并将其添加到环境变量中:
git clone https://chromium.googlesource.com/chromium/tools/depot_tools.git
export PATH="$PATH:/path/to/depot_tools"

# 3. 通过工具 clone 代码,只 clone 最新的提交,忽略历史提交:
# !! 仓库很大,需要有稳定的梯子。
# !! 如果你对 Git 不感兴趣,也可以在 clone 完毕后删掉 .git 目录,
# !! 否则如果你的 shell 会自动展示 Git 信息,那每条命令运行都会很慢。
fetch --no-history chromium

# 4. 通过工具生成一个编译用的配置文件:
gn gen out/Default

# 5. 通过工具编译:
# !! 耗时很长,在我的 M1 Mac 上面花了接近 7 小时。
# !! 不过由于这类项目都会有编译缓存,因此简单修改代码后的重编译还不到 1 分钟。
autoninja -C out/Default chrome

# 6. 运行 Chromium
out/Default/Chromium.app/Contents/MacOS/Chromium

只要能看到下面这个界面,就说明编译没问题,你已经有一个自己的 Chromium 啦!

自己编译并运行的 Chromium

简单的调试方法

在之前的经历中,我通过 LOG 宏来打印自定义的数据,通过 base::debug::StackTrace().Print() 打印堆栈以确认调用链路。但这次似乎不太一样了——LOG 的说明文档没有了,并且我直接调用会报编译错误;打印堆栈也是直接报编译错误,说找不到 StackTrace 方法。

凭借一点点 C++ 的知识,我发现在 v8 这个 namespace 里,这两个东西都是被重定义了——

  • LOGv8/src/logging/log.h 里面被重定义,需要提供 v8 isolate,但 V8ConsoleMessageStoragecontextGroup 级别的 class,没法提供具体某一个 context 的 isolate。因此我只好先用 std::cout 临时代替一下。
  • debugv8 这个 namespace 下也被重新实现了一次,需要用 v8::base::debug::StackTrace().Print() 来代替。

运行并查看结果

首先我在 V8ConsoleMessageStorage::addMessage 里面打印一下堆栈,确认了之前代码追踪的结果,确实是经过这条调用链路进来的。

==== C stack trace ===============================
[18709:259:0227/174421.484558:INFO:CONSOLE(6)] "[object Object]", source: file:///Users/rexzeng/Desktop/test.html (6)
    0  libv8_libbase.dylib 0x0000000114a0e8b4 v8::base::debug::StackTrace::StackTrace() + 24
    1  libv8.dylib         0x00000002dd939f40 v8_inspector::V8ConsoleMessageStorage::addMessage(std::Cr::unique_ptr<v8_inspector::V8ConsoleMessage, std::Cr::default_delete<v8_inspector::V8ConsoleMessage>>) + 912
    2  libv8.dylib         0x00000002dd93ff28 v8_inspector::(anonymous namespace)::ConsoleHelper::reportCall(v8_inspector::ConsoleAPIType, std::Cr::vector<v8::Local<v8::Value>, std::Cr::allocator<v8::Local<v8::Value>>> const&) + 204
    3  libv8.dylib         0x00000002dd93cf54 v8_inspector::(anonymous namespace)::ConsoleHelper::reportCall(v8_inspector::ConsoleAPIType) + 564
    4  libv8.dylib         0x00000002dd93d484 v8_inspector::V8Console::Log(v8::debug::ConsoleCallArguments const&, v8::debug::ConsoleContext const&) + 332
    5  libv8.dylib         0x00000002dc46a960 v8::internal::(anonymous namespace)::ConsoleCall(v8::internal::Isolate*, v8::internal::BuiltinArguments const&, void (v8::debug::ConsoleDelegate::*)(v8::debug::ConsoleCallArguments const&, v8::debug::ConsoleContext const&)) + 808
    6  libv8.dylib         0x00000002dc465e90 v8::internal::Builtin_Impl_ConsoleLog(v8::internal::BuiltinArguments, v8::internal::Isolate*) + 84
    7  libv8.dylib         0x00000002dc465aa8 v8::internal::Builtin_ConsoleLog(int, unsigned long*, v8::internal::Isolate*) + 208
    8  ???                 0x0000000377b4f8a8 0x0 + 14893250728
    9  ???                 0x00000003778b339c 0x0 + 14890513308
    10 ???                 0x00000003778ad55c 0x0 + 14890489180
    11 ???                 0x00000003778ad1e8 0x0 + 14890488296
    12 libv8.dylib         0x00000002dc731f54 v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) + 5292

那么为什么代码中的限制不生效呢?我在限制附近加了一段 log 来分析原因:。

+ std::cout << "[rex] V8ConsoleMessageStorage::addMessage called." << std::endl;
+ std::cout << "[rex] Current, new, limit = " << m_estimatedSize << ", "
+           << message->estimatedSize() << ", " << maxConsoleMessageV8Size
+           << std::endl;

  while (m_estimatedSize + message->estimatedSize() > maxConsoleMessageV8Size &&
        !m_messages.empty()) {
+   std::cout << "[rex] Estimate size exceeded, removing oldest message."
+             << std::endl;
    m_estimatedSize -= m_messages.front()->estimatedSize();
    m_messages.pop_front();
  }

  m_messages.push_back(std::move(message));
  m_estimatedSize += m_messages.back()->estimatedSize();

结果发现,这个循环根本就没进去,因为 message->estimatedSize() 的大小始终是 50!想要超过 maxConsoleMessageV8Size 这个 10485760 的限制实在是过于困难了。

[rex] V8ConsoleMessageStorage::addMessage called.
[rex] Current, new, limit = 0, 50, 10485760
[23733:259:0227/175711.516016:INFO:CONSOLE(23)] "[object Object]", source: file:///Users/rexzeng/Desktop/test.html (23) [rex] V8ConsoleMessageStorage::addMessage called.
[rex] Current, new, limit = 50, 50, 10485760
[23733:259:0227/175713.549701:INFO:CONSOLE(23)] "[object Object]", source: file:///Users/rexzeng/Desktop/test.html (23) [rex] V8ConsoleMessageStorage::addMessage called.
[rex] Current, new, limit = 100, 50, 10485760
[23733:259:0227/175715.563253:INFO:CONSOLE(23)] "[object Object]", source: file:///Users/rexzeng/Desktop/test.html (23) [rex] V8ConsoleMessageStorage::addMessage called.
[rex] Current, new, limit = 150, 50, 10485760
[23733:259:0227/175717.693054:INFO:CONSOLE(23)] "[object Object]", source: file:///Users/rexzeng/Desktop/test.html (23) [rex] V8ConsoleMessageStorage::addMessage called.
[rex] Current, new, limit = 200, 50, 10485760

明明我 log 的对象里面有一个很长的字符串,为什么预估大小只有 50 呢?看来 estimatedSize 可能有点问题。点进去一看,发现它取的是实例内部的 m_message 的长度:

int estimatedSize() const {
  return m_v8Size + static_cast<int>(m_message.length() * sizeof(UChar));
}

不合适的取值来源

从代码中可以发现,在 V8ConsoleMessage 类中,m_message 只是一个 String16 类型(定义在 v8/src/inspector/string-16.h,其实就是 UTF-16 的一个 C++ 实现),实际的值(类型是 v8::Value)其实存在一个 private 属性中:

using Arguments = std::vector<std::unique_ptr<v8::Global<v8::Value>>>;

经过简单查看,m_message 其实就是 log 里面出现的 "[object Object]",自然长度固定。那么如果我 log 的不是对象,而是只有一个长字符串呢?我简单改了一下代码(为了避免被刷屏,我特地改小了消息体,只有 10 的长度):

  const obj = {
    usagedMemory,
-   str: Array(1 * MB).fill(0).map(() => Math.random()),
+   str: Array(10).fill(0).map(() => Math.random()),
  };
- console.log(obj);
+ console.log(obj.str);

果然,预估大小变了,每条消息大概在 400 左右:

[rex] V8ConsoleMessageStorage::addMessage called: 0.006429781392031542,0.7025972903865423,0.10886522086870132,0.7463988173118989,0.1726929587177901,0.4041939919687627,0.6177604000139703,0.5011661616460559,0.12152624198222584,0.42717062777130876
[rex] Current, new, limit = 0, 404, 10485760
[29381:259:0227/181116.796558:INFO:CONSOLE(23)] "0.006429781392031542,0.7025972903865423,0.10886522086870132,0.7463988173118989,0.1726929587177901,0.4041939919687627,0.6177604000139703,0.5011661616460559,0.12152624198222584,0.42717062777130876", source: file:/// Users/rexzeng/Desktop/test.html (23)
[rex] V8ConsoleMessageStorage::addMessage called: 0.4775464572140946,0.22521271497851258,0.3548952458618082,0.07826429207660479,0.7868981992965354,0.9738662411476406,0.4493962839312635,0.17173905749902962,0.41509559133406393,0.6175669281153542
[rex] Current, new, limit = 404, 402, 10485760
[29381:259:0227/181116.854073:INFO:CONSOLE(23)] "0.4775464572140946,0.22521271497851258,0.3548952458618082,0.07826429207660479,0.7868981992965354,0.9738662411476406,0.4493962839312635,0.17173905749902962,0.41509559133406393,0.6175669281153542", source: file:/// Users/rexzeng/Desktop/test.html (23)
[rex] V8ConsoleMessageStorage::addMessage called: 0.016472809214265194,0.8297652370608959,0.5951015092506107,0.014495767431445872,0.04746432220371455,0.7227116481240548,0.9557890005161374,0.6282763394913704,0.3914123998466803,0.29088587247350106
[rex] Current, new, limit = 806, 406, 10485760

值得注意的是,虽然 m_message 字段看起来像是对 log 的值做 toString() 之后的结果,但实际上并不是。通过追踪代码可以看到 V8ConsoleMessage::createForConsoleAPI 函数(传送门)和 V8ValueStringBuilder::append 函数(传送门)的实现,最终定位到了 这里

if (value->IsObject() && !value->IsDate() && !value->IsFunction() &&
    !value->IsNativeError() && !value->IsRegExp()) {
  v8::Local<v8::Object> object = value.As<v8::Object>();
  v8::Local<v8::String> stringValue;
  if (object->ObjectProtoToString(m_context).ToLocal(&stringValue))
    return append(stringValue);
}

也就是类似于 JavaScript 里面的 Object.prototype.toString.call 的效果。可以使用下面这段 JavaScript 代码来验证——虽然在 JavaScript 里面强转 string 的结果是 "Rex Zeng is the greatest alive",但 std::cout 的结果依旧是 "[object Object]"

console.log({
  toString: () => {
    return 'Rex Zeng is the greatest alive';
  },
});

自此可以得出结论:Chromium 对 console.log 总大小限制失效的原因,是因为其在判断时没有使用合适的方式,导致预估大小与实际大小严重不符。

那么——该不该用 console.log?

本文只是在讨论“不打开 DevTools 时 console.log 是否还会造成内存泄漏”,至于在生产环境使用 console.log 的合理性不在讨论范围中。事实上对于大多数页面,log 打多打少并没有太大影响,而对于可能需要常开的页面(如 Telegram Web、企业监控大屏),内存占用的不断飙升最终会导致页面崩溃,这就必须要注意了。

如果因为一些原因,希望避免在生产环境使用 console.log,可以用 ESLint 帮助开发养成习惯,也可以通过编译器插件直接在 NODE_ENV === 'production' 时去除相关的代码。

版权声明:除文章开头有特殊声明的情况外,所有文章均可在遵从 CC BY 4.0 协议的情况下转载。
上一篇: 多版本共存——巨型项目组件库升级的必经之路
下一篇: 为 PNPM peer 添加 NPM alias 支持(PNPM 与 VSCode 动态调试入门)

这是我们共同度过的

第 2686 天