Search code examples
google-chromegarbage-collectionchromiumv8

Writing Chrome/V8 --trace-gc output to a file - stdout redirection does not work

We are working on an automated system for memory performance monitoring.

We start Chrome with proper flags --trace-gc --trace-gc-verbose both on Windows7 and MacOSX High Sierra.

The output is printed and visible on the console. However capturing the output with standard stream redirection does not work:

What do we do:

MacOS X: ./Google\ Chrome --js-flags="--trace-gc --trace-gc-verbose" > log.txt 2>&1

Windows: chrome --no-sandbox --js-flags="--trace_gc --trace_gc_verbose" > log.txt 2>&1

What gets written into the log file is only a part of what you can see on the screen: all gc-related data is missing in the file although abundant in the terminal window (you can see all the data when you run the app without stream capture at all).

We suppose a new process for V8 is run and it's output is not directed to stdout, though somewhat it gets printed to the console itself.

The V8 C++ code shows no mark of such a strange redirect, pretty clean standard code, in fact one can record gc-output of node --trace-gc script.js without any problem with standard stdout/stderr. It seems Chrome adds the undesired behavior.

Question how to record Chrome gc-related data to a file both on Windows and MacOS X.

Partial, unacceptable solution on POSIX-based systems we can grab all the terminal output with script command. The dump contains all the data we need, but the solution does not cover Windows scenario (we do need tests on Windows) and in fact it does not solve the problem neither explains the reason behind the lacking data, it simply hides the problem away.

Solution

  • I think there are two things worth being pointed out.

    1. The only output that is actually being redirected is Chrome-related. I mean if we redirect stderr to a file we can see the errors in this file, but only Chrome's errors not V8's.
    2. I wanted to use script command as I tried Powershell Start-Transcript, Tee and a few other options. It has turned out (no suprises here) that Windows has no command that can be used to achieve desired effect (AFAIK). So I used Babun (http://babun.github.io/) which is basically preconfigured Cygwin. No GC log has been displayed. Only Chrome's related stuff. I think that V8's logs are not being forwarded to Cygwin.

    UPDATE:
    This issue may be somehow related with these:

    1. Chrome spawns many processes and from what I can see from logs - GC logs are gathered from child process (different PID than one related with opened terminal window). I do not know how this alone could affect STDOUT redirection. It's just a fact I noticed.
    2. I found out that an application may know if its STOUD is being redirected and handle this situation differently - e. i. using buffers without flushing when STDOUT is being redirected to a file but not if it is printed on the console.

    UPDATE:
    I have created a following bug: https://bugs.chromium.org/p/chromium/issues/detail?id=865876#c3
    It seems like it was noticed and someone is going to take care of it.

    UPDATE:
    It seems like ChromeDriver can do exactly what we need - http://chromedriver.chromium.org/logging/performance-log
    Another workaround would be to run Chrome with --enable-precise-memory-info and the periodically invoke window.performance.memory, but that command does not provide us with nearly as much data as ChromeDriver