pretty-ts-errors icon indicating copy to clipboard operation
pretty-ts-errors copied to clipboard

Extension causes high cpu load

Open LaraMateo opened this issue 1 year ago • 12 comments
trafficstars

  • Issue Type: Performance
  • Extension Name: pretty-ts-errors
  • Extension Version: 0.5.4
  • OS Version: Darwin arm64 23.5.0
  • VS Code version: 1.91.1

:warning: Make sure to attach this file from your home-directory: :warning:file:///var/folders/mv/15wtxvc57854ydjbmr1p670r0000gq/T/YoavBls.pretty-ts-errors-unresponsive.cpuprofile.txt

Find more details here: https://github.com/microsoft/vscode/wiki/Explain-extension-causes-high-cpu-load

LaraMateo avatar Jul 23 '24 21:07 LaraMateo

@LaraMateo Could you attach the file mentioned in the generated report?

kevinramharak avatar Jul 24 '24 08:07 kevinramharak

I have been seeing this issue since the last minor release, here is the file

YoavBls.pretty-ts-errors-unresponsive.cpuprofile.txt

AhmedBaset avatar Aug 10 '24 08:08 AhmedBaset

@AhmedBaset Thanks, that helps a lot.

@yoavbls I used https://lahmatiy.github.io/cpupro as it gives a pretty good overview of cpuprofile's. I also ran a production build on the v0.6.0 with the sourcemaps enabled. Then using npx source-map-cli resolve <line> <col> --context 3 (see https://www.npmjs.com/package/source-map-cli) to resolve it to the source code, we finally have some way of figuring out where the extension seems to stall:

NOTE: the sourcemaps generated vs the cpuprofile seems to be off by 1 line, not sure why, but adding 1 to the line number (243 instead of 242). I'm not 100% sure if thats correct, if i try to apply the same idea to #118 it doesnt really seem to map correctly. But for the provided cpu profile I seem to be able to realiably map the whole stack trace up the call chain, so I am pretty confident.

If my attempt of mapping the cpuprofile to the sourcemap is correct, it seems like an abnormal amount of time is spent during the function convertToValidType, NQ in the sourcemap:

image

> npx source-map-cli resolve dist/extension.js.map --context 3 243 146
Maps to ../src/format/formatTypeBlock.ts:54:28 (type)

  }
}

const convertToValidType = (type: string) =>
                            ^
  `type x = ${type
    // Add missing parentheses when the type ends with "...""
    .replace(/(.*)\.\.\.$/, (_, p1) => addMissingParentheses(p1))

The source of the function:

const convertToValidType = (type: string) =>
  `type x = ${type
    // Add missing parentheses when the type ends with "...""
    .replace(/(.*)\.\.\.$/, (_, p1) => addMissingParentheses(p1))
    // Replace single parameter function destructuring because it's not a valid type
    // .replaceAll(/\((\{.*\})\:/g, (_, p1) => `(param: /* ${p1} */`)
    // Change `(...): return` which is invalid to `(...) => return`
    .replace(/^(\(.*\)): /, (_, p1) => `${p1} =>`)
    .replaceAll(/... (\d{0,}) more .../g, (_, p1) => `___${p1}MORE___`)
    .replaceAll(/... (\d{0,}) more ...;/g, (_, p1) => `___MORE___: ${p1};`)
    .replaceAll("...;", "___KEY___: ___THREE_DOTS___;")
    .replaceAll("...", "__THREE_DOTS__")};`;

I did some manual testing to see if there is a regex DOS somewhere hiding in here, but I can't really find a reproducible case. The only somewhat shady regex might be the first one. It uses the replacer function addMissingParentheses, which uses a stack and a while loop that doesnt end until the stack is empty. Maybe that loop never ends in some edge case? But I'm not sure since function call doesn't seem to show on the profiler.

As I mentioned, i tried to do the same method to #102 but for some reason the generated source map does not seem to work for the build at the v0.5.4 branch (theres no tag btw, its hidden in this commit 2531440478077fd3f3335e3e3d1b92c9679eb1bc). It does seem that the cases are unrelated though, the stalling function XX in that cpuprofile seems to point the prettier prettify function that uses the typescript parser.


Lots of text and research, but not really anywhere yet, I feel like these issues are going to be impossible to solve without proper reproducible cases 😞 .

kevinramharak avatar Aug 10 '24 20:08 kevinramharak

Great work Kevin! Thank you! I agree it'll be impossible to know for sure unless we'll have reproduction but the addMissingParentheses is a pretty direction to investigate. I'm not sure if it can get stuck in the while loop because it's popping the stack of the open parentheses but there are also some regexes that could be expansive, it may be that

yoavbls avatar Aug 19 '24 21:08 yoavbls

{
    "nodes": [
        {
            "id": 1,
            "callFrame": {
                "functionName": "(root)",
                "scriptId": "0",
                "url": "",
                "lineNumber": -1,
                "columnNumber": -1
            },
            "hitCount": 0,
            "children": [
                2
            ]
        },
        {
            "id": 2,
            "callFrame": {
                "functionName": "processTimers",
                "scriptId": "10",
                "url": "node:internal/timers",
                "lineNumber": 503,
                "columnNumber": 24
            },
            "hitCount": 0,
            "children": [
                3
            ]
        },
        {
            "id": 3,
            "callFrame": {
                "functionName": "listOnTimeout",
                "scriptId": "10",
                "url": "node:internal/timers",
                "lineNumber": 523,
                "columnNumber": 24
            },
            "hitCount": 0,
            "children": [
                4
            ]
        },
        {
            "id": 4,
            "callFrame": {
                "functionName": "",
                "scriptId": "141",
                "url": "pii_removed/extensionHostProcess.js",
                "lineNumber": 29,
                "columnNumber": 2231
            },
            "hitCount": 0,
            "children": [
                5
            ]
        },
        {
            "id": 5,
            "callFrame": {
                "functionName": "resume",
                "scriptId": "141",
                "url": "pii_removed/extensionHostProcess.js",
                "lineNumber": 29,
                "columnNumber": 1871
            },
            "hitCount": 0,
            "children": [
                6
            ]
        },
        {
            "id": 6,
            "callFrame": {
                "functionName": "fire",
                "scriptId": "141",
                "url": "pii_removed/extensionHostProcess.js",
                "lineNumber": 29,
                "columnNumber": 849
            },
            "hitCount": 0,
            "children": [
                7
            ]
        },
        {
            "id": 7,
            "callFrame": {
                "functionName": "B",
                "scriptId": "141",
                "url": "pii_removed/extensionHostProcess.js",
                "lineNumber": 29,
                "columnNumber": 659
            },
            "hitCount": 0,
            "children": [
                8
            ]
        },
        {
            "id": 8,
            "callFrame": {
                "functionName": "",
                "scriptId": "141",
                "url": "pii_removed/extensionHostProcess.js",
                "lineNumber": 24,
                "columnNumber": 5322
            },
            "hitCount": 0,
            "children": [
                9
            ]
        },
        {
            "id": 9,
            "callFrame": {
                "functionName": "fire",
                "scriptId": "141",
                "url": "pii_removed/extensionHostProcess.js",
                "lineNumber": 29,
                "columnNumber": 849
            },
            "hitCount": 0,
            "children": [
                10
            ]
        },
        {
            "id": 10,
            "callFrame": {
                "functionName": "C",
                "scriptId": "141",
                "url": "pii_removed/extensionHostProcess.js",
                "lineNumber": 29,
                "columnNumber": 770
            },
            "hitCount": 0,
            "children": [
                11
            ]
        },
        {
            "id": 11,
            "callFrame": {
                "functionName": "",
                "scriptId": "141",
                "url": "pii_removed/extensionHostProcess.js",
                "lineNumber": 156,
                "columnNumber": 35581
            },
            "hitCount": 0,
            "children": [
                12
            ]
        },
        {
            "id": 12,
            "callFrame": {
                "functionName": "",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 270,
                "columnNumber": 136
            },
            "hitCount": 0,
            "children": [
                13
            ]
        },
        {
            "id": 13,
            "callFrame": {
                "functionName": "",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 270,
                "columnNumber": 161
            },
            "hitCount": 0,
            "children": [
                14
            ]
        },
        {
            "id": 14,
            "callFrame": {
                "functionName": "",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 270,
                "columnNumber": 310
            },
            "hitCount": 0,
            "children": [
                15
            ]
        },
        {
            "id": 15,
            "callFrame": {
                "functionName": "LD",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 257,
                "columnNumber": 29
            },
            "hitCount": 0,
            "children": [
                16
            ]
        },
        {
            "id": 16,
            "callFrame": {
                "functionName": "kL",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 242,
                "columnNumber": 841
            },
            "hitCount": 0,
            "children": [
                17
            ]
        },
        {
            "id": 17,
            "callFrame": {
                "functionName": "",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 242,
                "columnNumber": 1864
            },
            "hitCount": 0,
            "children": [
                18
            ]
        },
        {
            "id": 18,
            "callFrame": {
                "functionName": "e_",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 241,
                "columnNumber": 82
            },
            "hitCount": 0,
            "children": [
                19
            ]
        },
        {
            "id": 19,
            "callFrame": {
                "functionName": "PQ",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 242,
                "columnNumber": 61
            },
            "hitCount": 0,
            "children": [
                20
            ]
        },
        {
            "id": 20,
            "callFrame": {
                "functionName": "NQ",
                "scriptId": "423",
                "url": "pii_removed/extension.js",
                "lineNumber": 242,
                "columnNumber": 146
            },
            "hitCount": 27712,
            "positionTicks": [
                {
                    "line": 243,
                    "ticks": 27712
                }
            ]
        }
    ],
    "startTime": 34105254834,
    "endTime": 34110700917,
    "samples": [
        // Omitted for brevity
    ]
}

tylerlaprade avatar Feb 05 '25 17:02 tylerlaprade

thanks for looking into this, any updates please? I had to disable the extension on my system (at least temporarily)

Kasopej avatar Feb 21 '25 02:02 Kasopej

This seems to happen when there are TS errors on objects that have HUGE types and generics. Perhaps a way to limit how deeply it looks

jasonlewicki avatar May 17 '25 01:05 jasonlewicki

I had to disable the extension on my system (at least temporarily)

I am unfortunately on the same boat :( any update, or at least any thought about how this could be handled to improve performance in the long term?

ramarivera avatar Jul 02 '25 07:07 ramarivera

Faced the same high CPU load issue, even when only having Rust and JSON files open - by using VSCode's bisect tool I found this extension to cause high CPU load. I did not look deeper but at least wanted to confirm the issue too.

davidmc971 avatar Jul 26 '25 15:07 davidmc971

I also encountered the issue. I'll attach my CPU profile as it looks much less bloated then in the comment

YoavBls.pretty-ts-errors-unresponsive.cpuprofile.txt

Ilanaya avatar Sep 25 '25 11:09 Ilanaya

@Ilanaya Thanks for your addition. I redid some of the profiling with the tool earlier mentioned (moved to https://discoveryjs.github.io/cpupro/#). It does confirm that the issue happens at:

/**
 * Try to make type prettier with prettier
 */
export function prettifyType(
  type: string,
  format: (type: string) => string,
  options?: { throwOnError?: boolean }
) {
  try {
    // Wrap type with valid statement, format it and extract the type back
    return convertToOriginalType(format(convertToValidType(type)));
    // ^ This line is where the cpu stalls
  } catch (e) {
    if (options?.throwOnError) {
      throw e;
    }
    return type;
  }
}

But I cannot figure out which call on that line is the issue. Its either a regex DOS in one of the convertToOriginalType or convertToValidType functions, or the passed down format function.

Tracing that parameter shows it is running prettier on the provided string:

import parserTypescript from "prettier/parser-typescript";
import { format } from "prettier/standalone";

export function prettify(text: string) {
  return format(text, {
    plugins: [parserTypescript],
    parser: "typescript",
    printWidth: 60,
    singleAttributePerLine: false,
    arrowParens: "avoid",
  });
}

So it could also be a case of providing a huge string to prettier, and it choking on something there. That's all i can really figure out for now.

As for @davidmc971 , it does not make sense for the issue to show up on JSON or Rust files, as these lines of code only run when vs code reports a diagnostic on a typescript file (or file with typescript code embedded). If you can provide a CPU profile we can check if its the same issue causing your high CPU load.

kevinramharak avatar Sep 25 '25 15:09 kevinramharak

@kevinramharak, would Biome be a faster alternative to Prettier?

tylerlaprade avatar Sep 25 '25 15:09 tylerlaprade