httpyac
httpyac copied to clipboard
Published
20 hours ago •
AnWeber
AnWeber
Performance optimization on windows
On a Windows work machine - which is a bit locked down and secured with MS Defender but generally not too slow - httpyac with no arguments takes about 30 seconds on the first run, and that time is similar on both powershell and msys2 bash (my preferred shell on Windows). On subsequent runs it takes about 2.5 seconds which is OK but not great.
That 2.5 seconds would be acceptable, but the Windows paging cache seems to expire rather quickly - so I'm back to a 20-30 second run before too long. Not sure if there's a way to increase it - looking into that.
Fortunately, I do have WSL bash, which takes around half a second, but I'd like to be able to run this without loading the virtual machine.
On my personal Windows laptop, which is a bit more powerful - Lenovo Slim Pro X - it's similarly super slow on the first run but then usually around 0.8 seconds.
I can't really share details from my work machine given security requirements, but I did profile it on my personal machine using the node 22 built-in profiler and asked github copilot what was slow. It didn't have too much to say unfortunately.
Steps:
- node.exe --prof /c/Users/ben/.version-fox/cache/nodejs/v-22.1.0/nodejs-22.1.0/node_modules/httpyac/bin/httpyac.js
- node.exe --prof-process ./isolate-00000210A0651000-10672-v8.log > prof-process-analysis.txt
Copilot Q&A
Copilot A:
The profile analysis you've provided indicates that most of the CPU time is spent in the shared libraries, specifically in node.exe and ntdll.dll. This suggests that the performance bottleneck might be in the Node.js runtime or in system-level operations, rather than in your JavaScript code.
The JavaScript functions listed in the profile (getNearestParentPackageJSON, normalizeString, and various built-in functions) each only account for a small fraction of the total CPU time.
Here are a few possibilities for why your program might be slow:
I/O operations: If your program is doing a lot of disk or network I/O, this could be slowing it down. I/O operations are often the bottleneck in Node.js programs.
CPU-intensive tasks: If your program is doing a lot of CPU-intensive tasks, this could be slowing it down. However, the profile suggests that this is not the main issue.
Node.js runtime: There could be some inefficiency in the Node.js runtime or in the way it's interacting with the system. The fact that a lot of time is spent in node.exe and ntdll.dll suggests this possibility.
To further diagnose the issue, you could try the following:
Use the --prof flag with the --log-timer-events flag to get more detailed timing information. Use a profiling tool like the Chrome DevTools profiler or the v8-profiler npm package to get a more detailed profile of your program. Look at the specific operations your program is doing when it's slow. Are there any I/O operations, network requests, or other potentially slow operations? Try running your program on a different system or with a different version of Node.js to see if the issue is specific to your current environment.
Copilot Q:
this is a profile analysis from the command node --prof-process which analyses isolate-00000210A0651000-10672-v8.log
why is this slow?
prof-process-analysis.txt:
Statistical profiling result from ./isolate-00000210A0651000-10672-v8.log, (69 ticks, 0 unaccounted, 0 excluded).
[Shared libraries]:
ticks total nonlib name
35 50.7% C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node.exe
26 37.7% C:\Windows\SYSTEM32\ntdll.dll
[JavaScript]:
ticks total nonlib name
1 1.4% 12.5% JS: +getNearestParentPackageJSON node:internal/modules/package_json_reader:137:37
1 1.4% 12.5% JS: *normalizeString node:path:66:25
1 1.4% 12.5% Builtin: NumberToString
1 1.4% 12.5% Builtin: FindOrderedHashMapEntry
1 1.4% 12.5% Builtin: Call_ReceiverIsNullOrUndefined
1 1.4% 12.5% Builtin: Call_ReceiverIsAny
1 1.4% 12.5% Builtin: CallFunction_ReceiverIsAny
1 1.4% 12.5% Builtin: Add_Baseline
[C++]:
ticks total nonlib name
[Summary]:
ticks total nonlib name
8 11.6% 100.0% JavaScript
0 0.0% 0.0% C++
1 1.4% 12.5% GC
61 88.4% Shared libraries
[C++ entry points]:
ticks cpp total name
[Bottom up (heavy) profile]:
Note: percentage shows a share of a particular caller in the total
amount of its parent calls.
Callers occupying less than 1.0% are not shown.
ticks parent name
35 50.7% C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node.exe
16 45.7% C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node.exe
2 12.5% Builtin: RegExpPrototypeExec
1 50.0% JS: ~SideEffectFreeRegExpPrototypeExec node:internal/util:743:43
1 100.0% JS: ~splitRoot node:fs:2584:33
1 100.0% JS: ^realpathSync node:fs:2632:22
1 50.0% JS: ^SideEffectFreeRegExpPrototypeExec node:internal/util:743:43
1 100.0% JS: ^splitRoot node:fs:2584:33
1 100.0% JS: +realpathSync node:fs:2632:22
1 6.3% JS: ~toRealPath node:internal/modules/helpers:57:20
1 100.0% JS: ~Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ~resolveMainPath node:internal/modules/run_main:29:25
1 100.0% JS: ~executeUserEntryPoint node:internal/modules/run_main:159:31
1 6.3% JS: ~resolveExports node:internal/modules/cjs/loader:623:24
1 100.0% JS: ~Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ~Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 100.0% JS: ~Module._load node:internal/modules/cjs/loader:1015:24
1 6.3% JS: ~patchProcessObject node:internal/process/pre_execution:224:28
1 100.0% JS: ~prepareExecution node:internal/process/pre_execution:97:26
1 100.0% JS: ~prepareMainThreadExecution node:internal/process/pre_execution:53:36
1 100.0% JS: ~<anonymous> node:internal/main/run_main_module:1:1
1 6.3% JS: ~nbv C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node_modules\httpyac\node_modules\jsbn\index.js:129:17
1 100.0% JS: ~<anonymous> C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node_modules\httpyac\node_modules\jsbn\index.js:1:10
1 100.0% JS: ~<anonymous> C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node_modules\httpyac\node_modules\jsbn\index.js:1:1
1 100.0% JS: ^Module._compile node:internal/modules/cjs/loader:1413:37
1 6.3% JS: ~getHighWaterMark node:internal/streams/state:33:26
1 100.0% JS: ~ReadableState node:internal/streams/readable:260:23
1 100.0% JS: ~Duplex node:internal/streams/duplex:65:16
1 100.0% JS: ~Socket node:net:354:16
1 6.3% JS: ~compileSourceTextModule node:internal/modules/esm/utils:335:33
1 100.0% JS: ~moduleStrategy node:internal/modules/esm/translators:158:50
1 100.0% JS: ~callTranslator node:internal/modules/esm/loader:422:28
1 100.0% JS: ~moduleProvider node:internal/modules/esm/loader:435:7
1 6.3% JS: ~Module._extensions..json node:internal/modules/cjs/loader:1572:39
1 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 100.0% JS: ^Module.require node:internal/modules/cjs/loader:1302:36
1 6.3% JS: ~<anonymous> node:internal/modules/esm/translators:254:67
1 100.0% Builtin: CallApiCallbackGeneric
1 100.0% JS: ~run node:internal/modules/esm/module_job:253:12
1 100.0% Builtin: AsyncFunctionAwaitResolveClosure
1 6.3% JS: ~<anonymous> C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node_modules\httpyac\node_modules\tmp\lib\tmp.js:1:1
1 100.0% JS: ^Module._compile node:internal/modules/cjs/loader:1413:37
1 100.0% JS: ^Module._extensions..js node:internal/modules/cjs/loader:1513:37
1 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
1 6.3% JS: +wrapSafe node:internal/modules/cjs/loader:1356:18
1 100.0% JS: +Module._compile node:internal/modules/cjs/loader:1413:37
1 100.0% JS: +Module._extensions..js node:internal/modules/cjs/loader:1513:37
1 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
1 6.3% JS: +get exports node:internal/modules/package_json_reader:89:16
1 100.0% JS: ^trySelf node:internal/modules/cjs/loader:581:17
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 6.3% JS: +deserializePackageJSON node:internal/modules/package_json_reader:40:32
1 100.0% JS: +getNearestParentPackageJSON node:internal/modules/package_json_reader:137:37
1 100.0% JS: ^Module._extensions..js node:internal/modules/cjs/loader:1513:37
1 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
1 6.3% Builtin: ReflectGet
1 100.0% JS: ^getOwn node:internal/bootstrap/realm:204:16
1 100.0% JS: ^syncExports node:internal/bootstrap/realm:371:14
1 100.0% JS: ~<anonymous> node:internal/bootstrap/realm:357:15
1 6.3% Builtin: MapPrototypeGet
1 100.0% JS: +stat node:internal/modules/cjs/loader:223:14
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
10 28.6% JS: ^wrapSafe node:internal/modules/cjs/loader:1356:18
10 100.0% JS: ^Module._compile node:internal/modules/cjs/loader:1413:37
10 100.0% JS: ^Module._extensions..js node:internal/modules/cjs/loader:1513:37
10 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
10 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
5 14.3% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
4 80.0% JS: ^requireBuiltin node:internal/bootstrap/realm:420:24
1 25.0% JS: ~<anonymous> node:stream:1:1
1 100.0% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
1 100.0% JS: ^requireBuiltin node:internal/bootstrap/realm:420:24
1 25.0% JS: ~<anonymous> node:internal/perf/observe:1:1
1 100.0% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
1 100.0% JS: ^requireBuiltin node:internal/bootstrap/realm:420:24
1 25.0% JS: ~<anonymous> node:https:1:1
1 100.0% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
1 100.0% JS: ^compileForPublicLoader node:internal/bootstrap/realm:331:25
1 25.0% JS: ~<anonymous> node:http2:1:1
1 100.0% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
1 100.0% JS: ^compileForPublicLoader node:internal/bootstrap/realm:331:25
1 20.0% JS: +requireBuiltin node:internal/bootstrap/realm:420:24
1 100.0% JS: ~<anonymous> node:internal/http2/compat:1:1
1 100.0% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
1 100.0% JS: +requireBuiltin node:internal/bootstrap/realm:420:24
2 5.7% Builtin: SetPrototypeHas
2 100.0% JS: +realpathSync node:fs:2632:22
2 100.0% JS: ^toRealPath node:internal/modules/helpers:57:20
1 50.0% JS: ^tryFile node:internal/modules/cjs/loader:514:17
1 100.0% JS: ^tryExtensions node:internal/modules/cjs/loader:529:23
1 50.0% JS: +tryExtensions node:internal/modules/cjs/loader:529:23
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 2.9% JS: ^getNearestParentPackageJSON node:internal/modules/package_json_reader:137:37
1 100.0% JS: ^Module._extensions..js node:internal/modules/cjs/loader:1513:37
1 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 100.0% JS: ^Module.require node:internal/modules/cjs/loader:1302:36
26 37.7% C:\Windows\SYSTEM32\ntdll.dll
16 61.5% C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node.exe
6 37.5% JS: +getNearestParentPackageJSON node:internal/modules/package_json_reader:137:37
4 66.7% JS: ^Module._extensions..js node:internal/modules/cjs/loader:1513:37
4 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
4 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
2 33.3% JS: ^trySelf node:internal/modules/cjs/loader:581:17
2 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
2 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
4 25.0% JS: +realpathSync node:fs:2632:22
3 75.0% JS: ^toRealPath node:internal/modules/helpers:57:20
2 66.7% JS: ^tryFile node:internal/modules/cjs/loader:514:17
1 50.0% JS: ^tryPackage node:internal/modules/cjs/loader:472:20
1 50.0% JS: ^tryExtensions node:internal/modules/cjs/loader:529:23
1 33.3% JS: +tryExtensions node:internal/modules/cjs/loader:529:23
1 100.0% JS: +Module._findPath node:internal/modules/cjs/loader:665:28
1 25.0% JS: +toRealPath node:internal/modules/helpers:57:20
1 100.0% JS: +tryExtensions node:internal/modules/cjs/loader:529:23
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
2 12.5% JS: +tryExtensions node:internal/modules/cjs/loader:529:23
1 50.0% JS: ^tryPackage node:internal/modules/cjs/loader:472:20
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 50.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 6.3% JS: ~defaultResolve node:internal/modules/esm/resolve:1055:24
1 100.0% JS: ~defaultResolve node:internal/modules/esm/loader:531:17
1 100.0% JS: ~resolve node:internal/modules/esm/loader:501:10
1 100.0% JS: ~getModuleJob node:internal/modules/esm/loader:239:21
1 6.3% JS: +wrapSafe node:internal/modules/cjs/loader:1356:18
1 100.0% JS: +Module._compile node:internal/modules/cjs/loader:1413:37
1 100.0% JS: +Module._extensions..js node:internal/modules/cjs/loader:1513:37
1 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
1 6.3% JS: +tryFile node:internal/modules/cjs/loader:514:17
1 100.0% JS: ^finalizeEsmResolution node:internal/modules/cjs/loader:1238:31
1 100.0% JS: ^resolveExports node:internal/modules/cjs/loader:623:24
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 6.3% JS: +stat node:internal/modules/cjs/loader:223:14
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
3 11.5% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
2 66.7% JS: +requireBuiltin node:internal/bootstrap/realm:420:24
1 50.0% JS: ~<anonymous> node:readline:1:1
1 100.0% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
1 100.0% JS: ^compileForPublicLoader node:internal/bootstrap/realm:331:25
1 50.0% JS: ~<anonymous> node:perf_hooks:1:1
1 100.0% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
1 100.0% JS: +requireBuiltin node:internal/bootstrap/realm:420:24
1 33.3% JS: ^requireBuiltin node:internal/bootstrap/realm:420:24
1 100.0% JS: ~<anonymous> node:crypto:1:1
1 100.0% JS: ^compileForInternalLoader node:internal/bootstrap/realm:383:27
1 100.0% JS: ^compileForPublicLoader node:internal/bootstrap/realm:331:25
1 3.8% JS: ^wrapSafe node:internal/modules/cjs/loader:1356:18
1 100.0% JS: ^Module._compile node:internal/modules/cjs/loader:1413:37
1 100.0% JS: ^Module._extensions..js node:internal/modules/cjs/loader:1513:37
1 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 3.8% JS: ^stat node:internal/modules/cjs/loader:223:14
1 100.0% JS: ^tryFile node:internal/modules/cjs/loader:514:17
1 100.0% JS: ^tryExtensions node:internal/modules/cjs/loader:529:23
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 3.8% JS: ^readFileSync node:fs:441:22
1 100.0% JS: ^getMaybeCachedSource node:internal/modules/cjs/loader:1494:30
1 100.0% JS: ^Module._extensions..js node:internal/modules/cjs/loader:1513:37
1 100.0% JS: ^Module.load node:internal/modules/cjs/loader:1274:33
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 3.8% JS: ^read node:internal/modules/package_json_reader:107:14
1 100.0% JS: ^readPackage node:internal/modules/package_json_reader:126:21
1 100.0% JS: ^resolveExports node:internal/modules/cjs/loader:623:24
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 3.8% JS: ^finalizeResolution node:internal/modules/esm/resolve:236:28
1 100.0% JS: ^moduleResolve node:internal/modules/esm/resolve:887:23
1 100.0% JS: ^defaultResolve node:internal/modules/esm/resolve:1055:24
1 100.0% JS: ^defaultResolve node:internal/modules/esm/loader:531:17
1 100.0% JS: ^resolve node:internal/modules/esm/loader:501:10
1 1.4% JS: +getNearestParentPackageJSON node:internal/modules/package_json_reader:137:37
1 100.0% JS: +Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 100.0% JS: +Module.require node:internal/modules/cjs/loader:1302:36
1 100.0% JS: ^require node:internal/modules/helpers:177:31
1 100.0% JS: ~<anonymous> C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node_modules\httpyac\node_modules\chardet\encoding\utf8.js:1:1
1 1.4% JS: *normalizeString node:path:66:25
1 100.0% JS: +resolve node:path:162:10
1 100.0% JS: +toNamespacedPath node:path:622:19
1 100.0% JS: ^stat node:internal/modules/cjs/loader:223:14
1 100.0% JS: ^tryFile node:internal/modules/cjs/loader:514:17
1 100.0% JS: ^tryExtensions node:internal/modules/cjs/loader:529:23
1 1.4% Builtin: NumberToString
1 100.0% JS: +realpathSync node:fs:2632:22
1 100.0% JS: ^toRealPath node:internal/modules/helpers:57:20
1 100.0% JS: +tryExtensions node:internal/modules/cjs/loader:529:23
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 1.4% Builtin: FindOrderedHashMapEntry
1 100.0% Builtin: MapPrototypeGet
1 100.0% JS: +stat node:internal/modules/cjs/loader:223:14
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 1.4% Builtin: Call_ReceiverIsNullOrUndefined
1 100.0% JS: ^toRealPath node:internal/modules/helpers:57:20
1 100.0% JS: ^tryFile node:internal/modules/cjs/loader:514:17
1 100.0% JS: ^tryExtensions node:internal/modules/cjs/loader:529:23
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 1.4% Builtin: Call_ReceiverIsAny
1 100.0% JS: ^toRealPath node:internal/modules/helpers:57:20
1 100.0% JS: ~tryFile node:internal/modules/cjs/loader:514:17
1 100.0% JS: ^tryExtensions node:internal/modules/cjs/loader:529:23
1 100.0% JS: ~tryPackage node:internal/modules/cjs/loader:472:20
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 1.4% Builtin: CallFunction_ReceiverIsAny
1 100.0% JS: +stat node:internal/modules/cjs/loader:223:14
1 100.0% JS: ^Module._findPath node:internal/modules/cjs/loader:665:28
1 100.0% JS: ^Module._resolveFilename node:internal/modules/cjs/loader:1138:35
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 100.0% JS: +Module.require node:internal/modules/cjs/loader:1302:36
1 1.4% Builtin: Add_Baseline
1 100.0% JS: ^Module._load node:internal/modules/cjs/loader:1015:24
1 100.0% JS: +Module.require node:internal/modules/cjs/loader:1302:36
1 100.0% JS: ^require node:internal/modules/helpers:177:31
1 100.0% JS: ~<anonymous> C:\Users\ben\.version-fox\cache\nodejs\v-22.1.0\nodejs-22.1.0\node_modules\httpyac\node_modules\rxjs\dist\cjs\internal\observable\fromSubscribable.js:1:1
1 100.0% JS: ^Module._compile node:internal/modules/cjs/loader:1413:37
