search

microsoft / vscode

Visual Studio Code
https://code.visualstudio.com
MIT License
162.45k stars 28.62k forks source link

Tyepscript bug - V1.88.1 Mac/TS 5.4.5 #210345

Closed arielkark closed 2 months ago

arielkark commented 5 months ago

Does this issue occur when all extensions are disabled?: Yes

image

tsserver.log

VS Code Version: 1.88.1 Commit: e170252f762678dec6ca2cc69aba1570769a5d39 Date: 2024-04-10T17:43:08.196Z Electron: 28.2.8 ElectronBuildId: 27744544 Chromium: 120.0.6099.291 Node.js: 18.18.2 V8: 12.0.267.19-electron.0 OS: Darwin arm64 23.0.0

OS Version: 14.0

Typescript version 5.4.5

PurplProto commented 5 months ago

I'm also seeing this since the 1.88 release, I've had to roll back to 1.87.2. Intellisense does work for me, eventually, however, it's extremely slow and htop also shows tsserver.js maxing out 1 core even after my Code window has been untouched for 10 mins.

I have a different environment though Win11 - WSL2 with Node.js v20.11.1.

max06 commented 5 months ago

Joining the party... Devcontainer (Node 20.11.0, bun 1.1) on remote ssh host (Ubuntu 22.04). I can easily trigger it by doing anything in the git panel.

Edit: Looks like the vitest extension did participate in that party. Deactivated it, less issues visible. Is there a way to check the extensions on a remote target?

maslennikov commented 5 months ago

Same here on Linux. Increased CPU usage, very slow intellisense and basic file operations (like deleting or renaming).

Version: 1.88.1 Commit: e170252f762678dec6ca2cc69aba1570769a5d39 Date: 2024-04-10T17:34:12.840Z Electron: 28.2.8 ElectronBuildId: 27744544 Chromium: 120.0.6099.291 Node.js: 18.18.2 V8: 12.0.267.19-electron.0 OS: Linux x64 6.5.0-27-generic snap

mjbvz commented 4 months ago

Does this reproduce in the latest VS Code insiders build with all extensions disabled?

Specifically try disabling @mdx-js/typescript-plugin

max06 commented 4 months ago

I'm afraid I failed following your instructions - when I disable all extensions, I can't access the working environment, on a remote server, in a devcontainer 😅

Instead I got a trace:

getpid()                                = 415904
write(3, "{\"seq\":0,\"type\":\"response\",\"comm"..., 12213) = 12213
epoll_wait(14, [{events=EPOLLIN, data={u32=17, u64=17}}], 1024, 0) = 1
read(17, "\1\0\0\0\0\0\0\0", 1024)      = 8
epoll_wait(14, [], 1024, 0)             = 0
epoll_wait(14, [{events=EPOLLIN, data={u32=3, u64=3}}], 1024, 6267) = 1
recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="{\"seq\":6049,\"type\":\"request\",\"co"..., iov_len=65536}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 156
access("/tmp/vscode-typescript1000/00ec9a20685b911ea4ee/tscancellation-a085b65fe64847a262ae.tmp6049", F_OK) = -1 ENOENT (No such file or directory)
access("/tmp/vscode-typescript1000/00ec9a20685b911ea4ee/tscancellation-a085b65fe64847a262ae.tmp6049", F_OK) = -1 ENOENT (No such file or directory)
access("/tmp/vscode-typescript1000/00ec9a20685b911ea4ee/tscancellation-a085b65fe64847a262ae.tmp6049", F_OK) = -1 ENOENT (No such file or directory)
write(3, "{\"seq\":0,\"type\":\"response\",\"comm"..., 12124) = 12124
epoll_wait(14, [], 1024, 0)             = 0
epoll_wait(14, [{events=EPOLLIN, data={u32=3, u64=3}}], 1024, 6239) = 1
recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="{\"seq\":6050,\"type\":\"request\",\"co"..., iov_len=65536}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 155
write(17, "\1\0\0\0\0\0\0\0", 8)        = 8
access("/tmp/vscode-typescript1000/00ec9a20685b911ea4ee/tscancellation-a085b65fe64847a262ae.tmp6050", F_OK) = -1 ENOENT (No such file or directory)
futex(0x66c6df0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x66c6da0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x66c6df0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x66c6da0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x66c6df0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x66c6da0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x66c6df4, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x66c6da0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x695d078, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x7ffe6b3046a0, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x7269d499f7e8, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x7ffe6b3046a0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x7ffe6b3046a0, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x7269d499f860, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x7269d499f7e8, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x66c6df0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x66c6da0, FUTEX_WAKE_PRIVATE, 1) = 1

Captured from the only process stuck at 100% cpu:

node      415904  107 28.7 2610636 2116540 ?     Rl   08:57   6:58      |   \_ /vscode/vscode-server-insiders/bin/linux-x64/dbfe999c960339dcd8134196c0a180b562b7b17b-insider/node --max-old-space-size=3072 /vscode/vscode-server-insiders/bin/linux-x64/dbfe999c960339dcd8134196c0a180b562b7b17b-insider/extensions/node_modules/typescript/lib/tsserver.js --useInferredProjectPerProjectRoot --enableTelemetry --cancellationPipeName /tmp/vscode-typescript1000/00ec9a20685b911ea4ee/tscancellation-a085b65fe64847a262ae.tmp* --globalPlugins typescript-vue-plugin-bundle --pluginProbeLocations /home/node/.vscode-server-insiders/extensions/vue.volar-2.0.10 --locale en --noGetErrOnBackgroundUpdate --canUseWatchEvents --validateDefaultNpmLocation --useNodeIpc

The number in the tscancellation-file being checked is rapidly increasing, the trace above repeats itself all the time.

mjbvz commented 4 months ago

Looks like you have vue.volar enabled. Do this happen with it and all other extensions disabled?

max06 commented 4 months ago

For now I can say it still happens after disabling volar. That process started freaking out when I followed a definition into a node_module:

image

The trace looks the same as before.

I'll give it another shot tomorrow with as many extensions disabled as possible.

max06 commented 4 months ago

Uh, I've got something. I changed the loglevel of the typescript extension, now seeing very much (60MB in minutes) of 

Info 14950[22:31:34.022] Finding references to /workspaces/nimbus/node_modules/h3/dist/index.d.ts position 29296 in project /workspaces/nimbus/app/tsconfig.json
Info 14950[22:31:34.041] Finding references to /workspaces/nimbus/node_modules/h3/dist/index.d.ts position 29296 in project /workspaces/nimbus/app/server/tsconfig.json
Perf 14950[22:31:34.055] 29692::references: elapsed time (in milliseconds) 33.3095
Info 14951[22:31:34.055] response:
    {"seq":0,"type":"response","command":"references","request_seq":29692,"success":true,"body":{"refs":[{"file":"/workspaces/nimbus/node_modules/h3/dist/index.d.ts","start":{"line":671,"offset":18},"end":{"line":671,"offset":27},"contextStart":{"line":671,"offset":1},"contextEnd":{"line":671,"offset":122},"isWriteAccess":true,"isDefinition":true},{"file":"/workspaces/nimbus/node_modules/h3/dist/index.d.ts","start":{"line":1088,"offset":2598},"end":{"line":1088,"offset":2607},"contextStart":{"line":1088,"offset":1},"contextEnd":{"line":1088,"offset":2860},"isWriteAccess":true,"isDefinition":false},{"file":"/workspaces/nimbus/app/.nuxt/types/nitro-imports.d.ts","start":{"line":141,"offset":1502},"end":{"line":141,"offset":1511},"contextStart":{"line":141,"offset":1},"contextEnd":{"line":141,"offset":1769},"isWriteAccess":true,"isDefinition":false}],"symbolName":"setCookie","symbolStartOffset":18,"symbolDisplayString":"function setCookie(event: H3Event, name: string, value: string, serializeOptions?: CookieSerializeOptions): void"}}
Info 14951[22:31:34.055] request:
    {
      "seq": 29693,
      "type": "request",
      "command": "references",
      "arguments": {
        "file": "/workspaces/nimbus/node_modules/h3/dist/index.d.ts",
        "line": 681,
        "offset": 18
      }
    }
Info 14951[22:31:34.056] Finding references to /workspaces/nimbus/node_modules/h3/dist/index.d.ts position 29678 in project /workspaces/nimbus/app/tsconfig.json
Info 14951[22:31:34.077] Finding references to /workspaces/nimbus/node_modules/h3/dist/index.d.ts position 29678 in project /workspaces/nimbus/app/server/tsconfig.json
Perf 14951[22:31:34.092] 29693::references: elapsed time (in milliseconds) 36.6133
Info 14951[22:31:34.092] response:
    {"seq":0,"type":"response","command":"references","request_seq":29693,"success":true,"body":{"refs":[{"file":"/workspaces/nimbus/node_modules/h3/dist/index.d.ts","start":{"line":681,"offset":18},"end":{"line":681,"offset":30},"contextStart":{"line":681,"offset":1},"contextEnd":{"line":681,"offset":110},"isWriteAccess":true,"isDefinition":true},{"file":"/workspaces/nimbus/node_modules/h3/dist/index.d.ts","start":{"line":1088,"offset":1586},"end":{"line":1088,"offset":1598},"contextStart":{"line":1088,"offset":1},"contextEnd":{"line":1088,"offset":2860},"isWriteAccess":true,"isDefinition":false},{"file":"/workspaces/nimbus/app/.nuxt/types/nitro-imports.d.ts","start":{"line":141,"offset":490},"end":{"line":141,"offset":502},"contextStart":{"line":141,"offset":1},"contextEnd":{"line":141,"offset":1769},"isWriteAccess":true,"isDefinition":false}],"symbolName":"deleteCookie","symbolStartOffset":18,"symbolDisplayString":"function deleteCookie(event: H3Event, name: string, serializeOptions?: CookieSerializeOptions): void"}}
Info 14951[22:31:34.094] request:
    {
      "seq": 29694,
      "type": "request",
      "command": "references",
      "arguments": {
        "file": "/workspaces/nimbus/node_modules/h3/dist/index.d.ts",
        "line": 694,
        "offset": 18
      }
    }

repeating. Same file, different line specs.

Edit: It gets till the end 

      "arguments": {
        "file": "/workspaces/nimbus/node_modules/h3/dist/index.d.ts",
        "line": 1086,
        "offset": 18
      }

then starting again on top of that same file.

mjbvz commented 4 months ago

Can you share the full logs or an example project so I can reproduce the issue

max06 commented 4 months ago

Absolutely. While creating this repro, I accidentally found the culprit: Codiumate.

Repro: Here (This is a default nuxt starter repo created using npx nuxt init <app>, no modifications.)

Steps:

Trigger:

itzaks commented 4 months ago

I've also been seeing extremely high CPU usage, using 1.88. Also running vue and typescript projects, with the official vue extension. When downgrading to 1.87.2 my CPU went from 102% to 3% usage.

PurplProto commented 4 months ago

I'm also seeing this since the 1.88 release, I've had to roll back to 1.87.2. Intellisense does work for me, eventually, however, it's extremely slow and htop also shows tsserver.js maxing out 1 core even after my Code window has been untouched for 10 mins.

I have a different environment though Win11 - WSL2 with Node.js v20.11.1.

This no longer appears to be an issue for me in 1.89.1. Not entirely sure what version the issue was resolved in, but can confirm I've done a full day of work on 1.89.1 without seeing this issue 😊

mjbvz commented 2 months ago

@itzaks Please file an issue against the Vue extension. VS Code does not have built-in vue support

@max06 A spike when installing a new package is expected as we have to analyze is. Codiumate could also be causing issues so make sure to check it

Closing since we haven't heard back from the original poster. The most likely cause of this is a misbehaving extension or something like yarn pnp which patches our typescript code

max06 commented 2 months ago

I'd be very happy if it was just a spike. Sadly, it's a never-ending loop, analyzing the same file over and over again...