R·ex / Zeng


MUGer, hacker, developer, amateur UI designer, punster, Japanese learner.

Get to The Bottom: Does console.log Leak Memory When DevTools is Not Open?

TL;DR: Yes. And although Chromium has tried to limit it, it has not solved the problem because the method is inappropriate.

There are many reasons for memory leaks in JavaScript, such as DOM, timers, closures, unexpected global variables, and the topic of this article: console.log. There are two articles on Juejin about whether console.log will cause memory leaks:

The conclusion of these two articles is: there must be a leak when DevTools is open (the code in the article can obviously prove it), but if DevTools is not open, there seems to be no problem (the data of performance in the article can also prove it).

But combined with my own experience, I wonder: if it does not cause memory leaks, it means that the object has been GCed, then why can I still see the objects logged before opening DevTools after opening it? These objects must be stored somewhere and must still occupy memory. So, in the spirit of getting to the bottom of things, I decided to get the answer through experiments, conjectures, tracking code, etc.

Reproducible Memory Leak

In fact, someone in the comments of the article pointed out: as long as the object logged each time is different, memory overflow will occur regardless of whether DevTools is open. Here I take an example of a number array of length 1M, and simply modify the code in the article:

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();

I was originally going to use the OS's task manager to view memory usage, but in order to avoid the impact of other processes as well as the memory compression and virtual memory of the OS, I finally opened Chrome's own task manager.

You can see that the usagedMemory output on the page is always 9, but the memory usage of this tab in Chrome's task manager is always increasing until it crashes when it reaches 3.4~3.6 GB. After that, I tried again after closing the task manager, and the page still crashed, so it must be because it "exceeded the memory limit" rather than "the observation of the task manager will cause memory leaks".

test.html consumed 3.4 GB of memory

The page will crash even if DevTools is not open

This example alone is enough to prove that memory leaks will occur even if DevTools is not open. And it can be found that the data printed by console.log is not within the scope of performance.memory.totalJSHeapSize. So where did they go? I turned my attention to the Chromium source code.

Static Code Tracking

As a program that requires extremely high speed, most of Chromium's content (including v8) is written in C++. To track the code, you must first be able to see the code. Although I can clone the repository locally for tracking, the project is too large, the clone takes some time, and it will put a lot of pressure on my IDE. A better way is to search for code and track jumps through the official Chromium Code Search page.

At first, I tried to find project structure-related documents on the The Chromium Projects page, with the aim of directly finding the directory where the console API is located, but I came up empty-handed, so I could only search the code directly. Considering that console.log may be converted into a seemingly completely unrelated C++ function call, and that this function call is too general, I may find many document comments related results, so I turned to search for console info, because according to my experience it must be in the same module as the implementation of console.log, and it does not appear frequently.

Luck was on my side, the first result looked very close to the target:

The first result may be what I want

The file is v8/src/inspector/v8-console.h, according to the C++ project specification, .h files generally only have declarations and not implementations (which are called definitions on the website), so I first click in, then click on: the Log symbol in the code, the only definition result in the pop-up window, and the new pop-up on the right is the function we are looking for, as shown in the screenshot below.

The process of tracking code

This is just the first step, following this line of thought, you can track to reportCall, and then to the V8ConsoleMessageStorage::addMessage method, at the end of the function, the parameter message is appended to the end of a vector (a variable-length array provided by C++ STL) (link):

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

As for m_messages, it is a member variable of the V8ConsoleMessageStorage class, and each of the instance of this class is inside each v8 isolates, and is only created when needed, such as when calling console.log. Cloudflare has a good explanation of what v8 isolates are:

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.

It turns out that it exists inside the v8-related instance, so it seems reasonable that the performance API cannot get it.

Ineffective Limit in Chromium

It is noteworthy that there is a small judgment before the push_back in the code just tracked:

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();
}

You can see that Chromium limits the total estimated volume (estimateSize, which may be inaccurate) that m_messages can hold. If this limit is exceeded, the earliest message placed in m_messages will be deleted. The definition of this limit is maxConsoleMessageV8Size = 10 * 1024 * 1024, which is... 10 MB??

I think this value is too small. Our test code generates at least 1 MB of memory every 50 ms, even if the estimate is inaccurate, it should quickly exceed this limit. Could it be that the limit is ineffective? But I have no more clues through static analysis of the code, maybe dynamic debugging can help me understand more details.

Dynamic Debugging

Four years ago, I had the opportunity to compile and debug the Chromium project myself (through logging) (link to the article). With that experience, I decided to try again.

Compile Chromium (Again)

Since it has been a long time, I once again opened the guide of The Chromium Projects. The difference is that this time I didn't do it on an Ubuntu virtual machine, but directly on a Mac system, so I need to check the corresponding document for Mac: Checking out and building Chromium for Mac. The key steps are:

# 1. Install the full version of Xcode, not the command line version. If this command can output normally, it means the installation is complete:
ls `xcode-select -p`/Platforms/MacOSX.platform/Developer/SDKs

# 2. Install the official toolset `depot_tools`, and add it to the environment variable:
git clone https://chromium.googlesource.com/chromium/tools/depot_tools.git
export PATH="$PATH:/path/to/depot_tools"

# 3. Clone the code through the tool, only clone the latest commit, ignore historical commits:
# !! The repository is very large and requires a stable VPN.
# !! If you are not interested in Git, you can also delete the .git directory after cloning,
# !! Otherwise, if your shell automatically displays Git information, each command will run very slowly.
fetch --no-history chromium

# 4. Generate a configuration file for compilation through the tool:
gn gen out/Default

# 5. Compile through the tool:
# !! It takes a long time, it took nearly 7 hours on my M1 Mac.
# !! However, because projects like this have compilation caches, recompiling after simple code changes takes less than 1 minute.
autoninja -C out/Default chrome

# 6. Run Chromium
out/Default/Chromium.app/Contents/MacOS/Chromium

As long as you can see the following interface, it means that the compilation is correct, and you have your own Chromium!

Chromium compiled and run by yourself

Simple Debugging Methods

In my previous experience, I used the LOG macro to print custom data, and used base::debug::StackTrace().Print() to print the stack to confirm the call chain. But this time seems to be different - the documentation for LOG is gone, and I get a compilation error when I call it directly; printing the stack also gives a compilation error, saying that the StackTrace method cannot be found.

With a little C++ knowledge, I found that in the v8 namespace, both of these things are redefined -

  • LOG is redefined in v8/src/logging/log.h, and requires a v8 isolate, but V8ConsoleMessageStorage is a class at the contextGroup level, so it cannot provide the isolate of a specific context. So I had to temporarily replace it with std::cout.
  • debug is also re-implemented in the v8 namespace, and you need to use v8::base::debug::StackTrace().Print() instead.

Run and View Results

First, I print the stack in V8ConsoleMessageStorage::addMessage to confirm the results of the previous code tracking, and it does come in through this call chain.

==== 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

So why doesn't the limit in the code take effect? I added a log near the limit to analyze the reason:

+ 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();

And I found the codes inside the loop area never reached, because the size of message->estimatedSize() is always 50! It is too difficult to exceed the limit of 10485760 of maxConsoleMessageV8Size.

[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

It is clear that there is a long string in the object I logged, why is the estimated size only 50? It seems that estimatedSize may have some problems. I clicked in and found that it takes the length of m_message inside the instance:

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

Inappropriate Value Source

From the code, it can be found that in the V8ConsoleMessage class, m_message is just a String16 type (defined in v8/src/inspector/string-16.h, which is actually a C++ implementation of UTF-16), and the actual value (type is v8::Value) actually exists in a private attribute:

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

After a simple check, m_message is actually the "[object Object]" that appears in the log, so the length is fixed in no doubt. So what if I log a long string instead of an object? I simply changed the code (to avoid being flooded, I deliberately reduced the message body to only 10 in length):

  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);

Sure enough, the estimated size changed, each message is about 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

It is worth noting that although the m_message field looks like the result of toString() on the log value, it is not. By tracking the code, you can see the implementation of the V8ConsoleMessage::createForConsoleAPI function (link) and the V8ValueStringBuilder::append function (link), and finally located here:

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);
}

It is similar to the effect of Object.prototype.toString.call in JavaScript. You can use the following JavaScript code to verify - although the result of forcibly converting to string in JavaScript is "Rex Zeng is the greatest alive", the result of std::cout is still "[object Object]":

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

From this, we can conclude that the reason why the total size limit of console.log in Chromium is invalid is that it did not use an appropriate method when judging, resulting in a serious discrepancy between the estimated size and the actual size.

So - Should I Use console.log?

This article only discusses "whether console.log will cause memory leaks when DevTools is not opened", and the rationality of using console.log in the production environment is not within the scope of discussion. In fact, for most pages, whether you log more or less does not have much impact, but for pages that may need to be kept open all the time (such as Telegram Web, enterprise monitoring big screens), the continuous soaring of memory usage will eventually cause the page to crash, which must be paid attention to.

If for some reason you want to avoid using console.log in the production environment, you can use ESLint to help develop habits, and you can also use compiler plugins to directly remove related code when NODE_ENV === 'production'.

Disqus is loading... If it fails to load, please add disqus.com and disquscdn.com to your whitelist.

We've been together for

3858 days