Node: Node 10 profiler path output regression on Windows

Created on 22 May 2018 · 12Comments · Source: nodejs/node

Version: v10.1.0
Platform: Windows 10 x64 (1803)
Subsystem: v8 profiler

Summary:

With Node 10 on Windows, the v8 log generated via node --prof no longer quotes paths correctly, causing node --prof-process to treat the backslashes in the paths as escape sequences.

This causes a path like:
C:\Users\Ed\src\neutrino-dev\node_modules\webpack\lib\Stats.js

...to be output as:
C:\u0000\rc\u0000erder\node_modulesëck\u0000tats.js

...which doesn't make for the most readable profiles.

In addition, redirecting stdout when using --prof-process without the --preprocess, results in a binary file (whereas if there is no redirection, text is output to the console as expected).

I'm presuming this is a regression between v8 6.2 and 6.6.

STR:

node --prof node_modules\webpack\bin\webpack.js --mode production
node --prof-process --preprocess isolate-[IDENTIFIER]-v8.log > preprocessed.json
node --prof-process isolate-[IDENTIFIER]-v8.log > processed.txt
Repeat steps 1-3 using Node 8.11.2 instead, and compare output from each.

Expected:

Node 10.1.0 produces comparable output to Node 8.x, that correctly lists the filesystem paths for items in the profile.

Actual:

# Step 1 produces... (note difference in quoting)

Node 10.1.0:

v8-version,6,6,346,27,-node.6,0
shared-library,C:\Users\Ed\Desktop\node-v10.1.0-win-x64\node.exe,0x7ff64f880000,0x7ff650f0f000,0
shared-library,C:\WINDOWS\SYSTEM32\ntdll.dll,0x7ff9b1df0000,0x7ff9b1fd1000,0
shared-library,C:\WINDOWS\System32\KERNEL32.DLL,0x7ff9b0da0000,0x7ff9b0e52000,0
...

Node 8.11.2:

v8-version,6,2,414,54,0
shared-library,"C:\Users\Ed\Desktop\node-v8.11.2-win-x64\node.exe",0x7ff6f9ec0000,0x7ff6fb490000,0
shared-library,"C:\WINDOWS\SYSTEM32\ntdll.dll",0x7ff9b1df0000,0x7ff9b1fd1000,0
shared-library,"C:\WINDOWS\System32\KERNEL32.DLL",0x7ff9b0da0000,0x7ff9b0e52000,0
...

# Step 2 produces...

Node 10.1.0:

{
  "code": [
  {
    "name": "C:\u0000\rsktop\node-v10.1.0-win-x64\node.exe",
    "type": "SHARED_LIB"
  },
  {
    "name": "C:\u0000WS\u0000M32\ntdll.dll",
    "type": "SHARED_LIB"
  },
...

Node 8.11.2:

{
  "code": [
  {
    "name": "C:\\Users\\Ed\\Desktop\\node-v8.11.2-win-x64\\node.exe",
    "type": "SHARED_LIB"
  },
  {
    "name": "C:\\WINDOWS\\SYSTEM32\\ntdll.dll",
    "type": "SHARED_LIB"
  },
...

# Step 3 produces...

Node 10.1.0 (note: the binary output only occurs when redirecting stdout to a file):

5374 6174 6973 7469 6361 6c20 7072 6f66
696c 696e 6720 7265 7375 6c74 2066 726f
6d20 6973 6f6c 6174 652d 3030 3030 3031
3139 3031 3441 3539 4130 2d76 382e 6c6f
...

Node 8.11.2:

Statistical profiling result from isolate-0000027B49039D30-v8.log, (5485 ticks, 82 unaccounted, 0 excluded).

 [Shared libraries]:
   ticks  total  nonlib   name
   2551   46.5%          C:\WINDOWS\SYSTEM32\ntdll.dll
   1507   27.5%          C:\Users\Ed\Desktop\node-v8.11.2-win-x64\node.exe
...

v10.x

Source

edmorley

👍7

Most helpful comment

Seems like this just got fixed upstream: https://chromium.googlesource.com/v8/v8.git/+/29879461ceb4bc9b84b0ec38e4dd192fbf884dc2. I asked for a backport to 6.8 and I'll get that in if it's accepted.

BridgeAR on 24 Aug 2018

👍5 ❤1

All 12 comments

I temporary use the following solution:

node --prof node_modules/webpack/bin/webpack.js --mode production
sed -r 's/C\:\\[^,]+/"&"/g' isolate-[IDENTIFIER]-v8.log | sed -r '/C\:./ { s/\\/\//g }' > converted
node --prof-process converted > processed.txt

It results in the following output:

...
 [Shared libraries]:
   ticks  total  nonlib   name
     49   80.3%          "C:/Program Files/nodejs/node.exe"
      9   14.8%          "C:/WINDOWS/SYSTEM32/ntdll.dll"
...

tplk on 30 May 2018

👍3 👀1

I confirm the issue still exists with Node 10.9.0.
@tplk Thanks for your workaround. But when RegExp involved, such lines were still broken.

code-creation,RegExp,4,325150,0x1851d0746e0,1083,^(?=\n[ \t]*(\n|$))

I tried to apply similar fixes like adding "", but in vain anyway.
I'd like to know what's the behavior of regexp in log file in previous v8 versions and is there another workaround for it?