Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] primordial.js is not skipped by skipFiles on launch.json or settings.json #980

Closed
johan-apo opened this issue Apr 26, 2021 · 23 comments
Assignees
Labels
bug Issue identified by VS Code Team member as probable bug upstream

Comments

@johan-apo
Copy link

🐛 What is the bug? How can we reproduce it?

Just before the end of the debugging session, appears a new tab with primordials.js, it is a file located on
\<node_internals>\internal\per_context\primordials.js, inside the file, it places on the function uncurryThis. I have used
"<node_internals>/**" and "<node_internals>/**/*.js" and doesn't work. It is just a simple debugging on an index.js no fancy framework. I tried also disabling all the extensions, keep not working.

image
image
image
image
image
image

Please put here any steps, code or any information that can help us
reproduce the error on our side so we can fix it:

  1. Step 1
    An index.js file with the next code of the screenshot

  2. Step 2
    2.1 Use the auto attach - smart, run node index.js.
    2.2 Use a launch.json like in the screenshot and run the debugger with that config.
    Both ends with the same uncurryThis function on primordials.js

  3. Repeat changing the paths, restarting extension host, or killing vs code process and then open again. Nothing works.

Expected behavior

Don't open primordials.js when debug.

Debug output

Debug Console

baz
index.js:2
bar
index.js:7
foo
index.js:12

Developer Tools console

After clear console, and run the debugger, the console prints:

workbench.desktop.main.js:62 [Extension Host] [WakaTime][DEBUG] Sending heartbeat: c:\Users\usuario\.vscode\extensions\wakatime.vscode-wakatime-5.0.1\wakatime-cli\wakatime-cli.exe --file <node_internals>\internal\per_context\primordials.js --plugin "\"vscode/1.55.2 vscode-wakatime/5.0.1\"" --config C:\Users\usuario\.wakatime.cfg --log-file C:\Users\usuario\.wakatime.log
workbench.desktop.main.js:62 [Extension Host] [WakaTime][DEBUG] last heartbeat sent Apr 26, 2021 12:28 AM

Something about the extension WakaTime, I disabled it, restart, and re run debugger, and the problem keeps appearing.

Environment

Please tell us about your system and your project:
System: Windows 10 Home Version 21H1 OS build 19043.962 Experience Windows Feature Experience Pack 120.2212.3530.0

Visual Studio Code:
Version: 1.55.2 (user setup)
Commit: 3c4e3df9e89829dce27b7b5c24508306b151f30d
Date: 2021-04-13T09:35:57.887Z
Electron: 11.3.0
Chrome: 87.0.4280.141
Node.js: 12.18.3
V8: 8.7.220.31-electron.0
OS: Windows_NT x64 10.0.19043

Node.js version installed: 14.15.5

Project: index.js file with some functions and console.logs.

@johan-apo johan-apo added the bug Issue identified by VS Code Team member as probable bug label Apr 26, 2021
@connor4312
Copy link
Member

connor4312 commented Apr 26, 2021

You're pressing Step Out at the end of the file. When this happens, the debugger will try to step out to whoever called the function you're in, which is internal Node code when you're at the top level of a module. There's an existing bug in Node with blackbox patterns not working around async code, which is what you're hitting here.

To get around this, you should press Continue (keybinding: F5) instead of Step Out -- it doesn't seem like you actually want to step out in this case.

@mrcates
Copy link

mrcates commented Jun 10, 2021

I'm noticing that this is happening even with "Step Into" (F11).

This occurs when you Step Into (F11) an async function invocation or Step Into (F11) a return expression within an async function. In my humble opinion, this is not working as expected and is causing friction in debugging.

Example Code

1  class Math {
2    static async multiply(x, y) {
3      return x * y;
4    }
5  }
6
7  let result = await Math.multiply(x, y);
8
9  console.log(result);

What's Going Wrong

If you set a breakpoint on line 7 and Step Into (F11), you'll be taken into primordials.js as shown in the OP's example. If you continue to step into, you'll eventually get through to the multiply method. Then, pressing Step Into (F11) on line 3 will once again bring you back into primordials.js.

Why Is This Bad

Expecting the user to place breakpoints before and after every async function invocation and to use Run (F5) to avoid entering primordials.js is not a tractable solution and is undesired behavior because it breaks the cohesion and natural order of execution from the perspective of the user's code. I have no desire to step into internals whatsoever. I'm only interested in debugging my code.

This causes a giant amount of friction and wasted time, especially when new devs are trying to follow the execution path to learn new areas of code. This makes it very difficult to follow execution from end to end.

Expected Behavior

  1. When on a line which results in the invocation of an async function, Pressing F11 to enter an async function should take you directly into the async function being invoked (whether that's the argument destructuring process if applicable or straight into the first line in the function). For example, with the debugger paused on line 7 in the example above, pressing F11 should take me directly to line 3.
  2. When on a line with a return statement within an async function, Pressing F11 should return me back to the line after execution. For example, with the debugger paused on line 3 in the example above, Pressing F11 should take me straight to line 9.

IMO this issue should be reopened, please and thank you!

@connor4312
Copy link
Member

connor4312 commented Jun 10, 2021

@mrcates please share your log file by adding "trace": true to the launch.json. The location of the log file will be written to the debug console. However know that this is very likely a bug in Node.js or V8 rather than the debugger.

@mrcates
Copy link

mrcates commented Jun 11, 2021

well, interestingly enough this is fixed in the May release at least for Node 14 👍

Sounds like there's nothing more to see here!

@cefn
Copy link

cefn commented Jun 13, 2021

I'm also encountering the problem that every Step Into with 14.17.0 lands in primordials.js unfortunately and it is a huge obstacle to debugging typescript files in VSCode.

The tests I am debugging pass, and they run correctly in typescript using the local jest config and interactively from VSCode, except for debugging.

The configuration of my debugger is as follows, with parameters that previously worked to skip internal files I think...

  "jestrunner.debugOptions": {
    "terminal": "integratedTerminal",
    "smartStep": true,
    "skipFiles": ["<node_internals>/**", "${workspaceRoot}/**/node_modules/**"],
    "resolveSourceMapLocations": [
      "${workspaceFolder}/**",
      "!**/node_modules/**"
    ]
  },

However, even when stepping into a simple constructor function I end up landed in primordials.js

If I put a breakpoint on the line of the constructor call, AND a breakpoint on the first line of the constructor then the debugger successfully loads the first line of the constructor when choosing Step into.

image
image

However, if I don't explicitly add a breakpoint in the first line of the constructor (which should be the line it steps to) the interpreter seems to hang for 15 seconds and then drops me into primordials.js

image

The code line I am debugging is at https://github.com/cefn/lauf/blob/72ccc8f1c1781d26cf3238b811dcaf98a87ffe4c/modules/lauf-store/src/core/store.ts#L31

@connor4312
Copy link
Member

@cefn please share your log file by adding "trace": true to the launch.json. The location of the log file will be written to the debug console. However know that this is very likely a bug in Node.js or V8 rather than the debugger.

@cefn
Copy link

cefn commented Jun 13, 2021

I tried adding the flag into the jestrunner.debugOptions like...

  "jestrunner.debugOptions": {
    "trace": true,
    "smartStep": true,
    "skipFiles": ["<node_internals>/**", "${workspaceRoot}/**/node_modules/**"],
    "resolveSourceMapLocations": [
      "${workspaceFolder}/**",
      "!**/node_modules/**"
    ]
  },

It had apparently no effect, with the resulting command and full output with no breakpoints being like...

cefn@penguin:~/Documents/github/lauf$ node '/home/cefn/Documents/github/lauf/node_modules/.bin/jest' '/home/cefn/Documents/github/lauf/modules/lauf-store/test/core/store.test.ts' -c '/home/cefn/Documents/github/lauf/modules/lauf-store/jest.config.js'
 PASS  modules/lauf-store/test/core/store.test.ts
  Root Store: Core behaviour
    ✓ Create Store with list root (3 ms)
    ✓ Create Store with map root
    ✓ Create Store and pass watchers who are notified (2 ms)
    ✓ Can edit BasicStore (1 ms)
    ✓ Editing BasicStore replaces items iff on path to change (1 ms)

--------------------|---------|----------|---------|---------|-------------------
File                | % Stmts | % Branch | % Funcs | % Lines | Uncovered Line #s 
--------------------|---------|----------|---------|---------|-------------------
All files           |    74.6 |    54.55 |   63.41 |   72.17 |                   
 src                |     100 |      100 |     100 |     100 |                   
  index.ts          |     100 |      100 |     100 |     100 |                   
 src/core           |   60.98 |    54.55 |   48.28 |   56.76 |                   
  index.ts          |     100 |      100 |      50 |     100 |                   
  partition.ts      |   18.18 |        0 |    9.09 |   18.18 | 20-63,79          
  store.ts          |   92.86 |    66.67 |      80 |   92.31 | 18                
  watchable.ts      |   77.78 |      100 |   57.14 |   71.43 | 18-21             
  watchableState.ts |     100 |      100 |     100 |     100 |                   
 src/types          |     100 |      100 |     100 |     100 |                   
  index.ts          |     100 |      100 |     100 |     100 |                   
 test               |     100 |      100 |     100 |     100 |                   
  util.ts           |     100 |      100 |     100 |     100 |                   
 test/core          |     100 |      100 |     100 |     100 |                   
  storeSuite.ts     |     100 |      100 |     100 |     100 |                   
--------------------|---------|----------|---------|---------|-------------------
Test Suites: 1 passed, 1 total
Tests:       5 passed, 5 total
Snapshots:   0 total
Time:        1.608 s, estimated 15 s
Ran all test suites matching /\/home\/cefn\/Documents\/github\/lauf\/modules\/lauf-store\/test\/core\/store.test.ts/i.

In the context of Jest do I have to specify the debug parameters a different way? Not sure how I can get any launch.json config to be used, which is why I've relied on Jest Runner to make changes to the debugOptions itself.

See the section on debugOptions at https://marketplace.visualstudio.com/items?itemName=firsttris.vscode-jest-runner for how I currently aim to specify them (which I'm certain worked in previous versions). But I'm ready to follow suggestions if this is altogether the wrong way to debug a jest test suite.

@connor4312
Copy link
Member

The location should be printed to the Debug Console, it looks like you're looking at the Terminal output

@cefn
Copy link

cefn commented Jun 13, 2021

Brilliant. I found the log at ~/.config/Code/logs/20210613T082049/exthost1/ms-vscode.node-debug

It's attached. If there's a more legitimate way to run tests than through Jest Runner, which ensures the skipFiles and smartStep behaviour config gets passed properly I'm happy to try another route.

debugadapter-legacy.txt

@connor4312
Copy link
Member

It looks like that's using the old debugger (usually controlled by your user setting debug.javascript.usePreview). We no longer support that, please use the new debugger by turning that setting on and let me know if you hit issues.

@cefn
Copy link

cefn commented Jun 13, 2021

Yes, with that setting on the difference is night and day! Thanks so much for your help!

It no longer drops into node primordial.js and restricts itself to my source files with adequate source-mapping as far as I can see.

I think the remaining wierdness is real. For example the Javascript when calling a class constructor often looks as if it's executing elements of class definitions out-of-order when following Typescript source maps, but I think execution probably actually IS jumping over the place out of order because it's transpiled from Typescript, so it's a miracle it works at all. It's much much more usable now!

@kmeigcasan
Copy link

kmeigcasan commented Jun 24, 2021

@connor4312 I'm using debug.javascript.usePreview = true but still, the primordial.js is not skipped. Here's my launch.json:

{
 "version": "0.2.0",
 "configurations": [
        {
            "name": "Debug Docker",
            "type": "node",
            "request": "attach",
            "port": 9229,
            "address": "localhost",
            "localRoot": "${workspaceFolder}",
            "remoteRoot": "/var/www/app",
            "protocol": "inspector",
            "restart": true,
            "sourceMaps": true,
            "skipFiles": [
                "${workspaceRoot}/node_modules/**/*.js",
                "<node_internals>/**/*.js"
              ]
        }
   ]
}

My debugger works, but it only don't skip the said unnecessary js file. Please help, thank you!

@connor4312
Copy link
Member

Please share your log file using the instructions posted above

@kmeigcasan
Copy link

kmeigcasan commented Jun 25, 2021

Thanks for fast reply, @connor4312
I added "trace": true to the launch.json and here's the log.

@kmeigcasan
Copy link

@connor4312 Any update?

@dylankilkenny
Copy link

Also having this issue

launch.json

{
  // Use IntelliSense to learn about possible attributes.
  // Hover to view descriptions of existing attributes.
  // For more information, visit: https://go.microsoft.com/fwlink/?linkid=830387
  "version": "0.2.0",
  "configurations": [
    {
      "type": "pwa-node",
      "request": "launch",
      "name": "Launch TS Debugger",
      "sourceMaps": true,
      "trace": true,
      "skipFiles": [
        "<node_internals>",
        "<node_internals>/**/*.js",
        "${workspaceFolder}/node_modules/**/*.js",
        "loader.js",
        "async_hooks.js",
        "bootstrap.js",
        "**/async_hooks.js",
        "**/primordials.js",
        "**/webpack/bootstrap",
        "**/internal/**/*",
        "**/domain.js",
        "**/events.js"
      ],
      "smartStep": true,
      "args": ["${workspaceFolder}/src/data/PairsByVolume.ts"],
      "runtimeArgs": ["--nolazy", "-r", "ts-node/register/transpile-only"],
      "runtimeExecutable": "/Users/dylankilkenny/.nvm/versions/node/v14.9.0/bin/node"
    }
  ]
}

@connor4312
Copy link
Member

@connor4312 Any update?

You're hitting the referenced bug in V8. We blackbox the pattern ^internal\/per_context\/primordials\.js$, but V8 stops in that file.

@kmeigcasan
Copy link

kmeigcasan commented Jul 7, 2021

@connor4312 Yeah, thanks. In my previous comment, I used the default debugger in VSCode. After some research, I found your extension: https://github.com/microsoft/vscode-js-debug/#nightly-extension

I did the mentioned step 1-4 now, reopened VSCode, then did a debug again. Still, primordial.js showed. My launch.json is same to what I commented here before.

Here is the new log using your extension:
vscode-debugadapter-e0ee4acf.json.gz

Here is the info of my VSCode if you needed:
image

@kmeigcasan
Copy link

@connor4312 Hi Connor, any update on my issue?

@cawoodm
Copy link

cawoodm commented Aug 14, 2021

I can confirm this is still an (extremely frustrating) issue in the latest VS Code (1.59) - again and again I step out of an async function and land in a wilderness of uncurry, primoridals, async_hooks. I've tried every single variation of skipFiles I could find and VS Code "sometimes" just puts me in node_modules or node_internals. So unproductive I'm thinking of switching to a different IDE.

@connor4312
Copy link
Member

As mentioned before this is a bug in V8/Node.js

@connor4312
Copy link
Member

Fyi I've implemented "synthetic black boxing" in #1085 to get around the Node bugs

@raph90
Copy link

raph90 commented Aug 31, 2021

I am still having this issue. I've tried multiple different variations for "skipFlags", but when debugging async Jest tests I still end up in node_modules/regenerator-runtime/runtime.js and other files.
This wasn't a problem 2 days ago, so I'm wondering if there's been an update since then which is causing the issue.

@microsoft microsoft locked as resolved and limited conversation to collaborators Aug 31, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Issue identified by VS Code Team member as probable bug upstream
Projects
None yet
Development

No branches or pull requests

9 participants