clinicjs / node-clinic

Clinic.js diagnoses your Node.js performance issues
https://clinicjs.org
MIT License
5.67k stars 125 forks source link

Heap reported by clinic is very different from that reported by node #458

Open llimllib opened 1 year ago

llimllib commented 1 year ago

Expected Behavior

Current Behavior

Steps to Reproduce (for bugs)

  1. Run jest under clinic with --logHeapUsage: clinic doctor -- node node_modules/.bin/jest --logHeapUsage packages/models/__tests__/project
  2. Note that jest reports 469 mb max heap usage
    • PASS models packages/models/__tests__/project/model.test.ts (10.117 s, 469 MB heap size)
  3. Note that clinic reports we used ~40: image

What could be causing such a large difference? Jest uses process.memoryUsage().heapUsed to measure the heap size.

Sample upload

I don't feel comfortable uploading my work app's trace, unfortunately

Environment

RafaelGSS commented 1 year ago

I wasn't around when clinic heapprofiler was created so I don't know exactly if that's the expected behaviour. I'm guessing heapprofiler does count the amount of memory allocation during the profile while the process.memoryUsage().heapUsed gets the whole process memory (heap) used -- it's different because the process might hold 10mb but just allocate 1mb in objects.

@mcollina @jasnell would you be able to confirm that?

llimllib commented 1 year ago

I should have mentioned when I wrote this that --runInBand doesn't change the situation; I suspect it's something to do with the fact that node kicks off a child process. Here's the process tree, as reported by htop during a test run:

image

You can see there that the main jest process only has 86mb, while its child test-runner process is chomping up an order of magnitude more memory.

Is there any way to get at the child process?

RafaelGSS commented 1 year ago

Not really. Heapprofiler measures only the main process, in your case the main jest process.