tailwindcss icon indicating copy to clipboard operation
tailwindcss copied to clipboard

Tailwind CLI slow down / memory leak

Open FallDownTheSystem opened this issue 2 years ago • 9 comments

What version of Tailwind CSS are you using?

v3.0.22

What build tool (or framework if it abstracts the build tool) are you using?

None

What version of Node.js are you using?

v17.0.1

What browser are you using?

N/A

What operating system are you using?

Windows 10

Reproduction URL

https://github.com/FallDownTheSystem/tailwind-cli-slowdown

Describe your issue

After saving a file in the root folder, that triggers a rebuild by the Tailwind CLI watcher, while the rebuild is still in progress, I think some kind of memory leak happens.

The reproduction requires a file to be saved very rapidly to showcase it, but on larger projects, it can happen naturally, as the build times are longer to begin with.

I'll paste the reproduction steps and explanation I added to the README.md of the minimal reproduction demo here. I've also attached a video that showcases the behavior.

https://github.com/FallDownTheSystem/tailwind-cli-slowdown

  1. npm install
  2. npm run watch
  3. Spam save ./folder/noonroot.aspx or ./folder/nonroot2.aspx (On Windows you can hold down ctrl + save to rapidly save the file)
  4. Spam save ./root.aspx for a long while
  5. Try to spam save one of the nonroot.aspx files again

The CLI now gets "stuck" on adding the rebuild step to the promise chain faster than it can process then, making the chain longer and longer. Once you stop spamming save, the chain will unwind and all the rebuilds will complete. But now each time you attempt to save, the process allocates a larger chunk of memory than originally.

This is even more evident if you spam save the tailwind.config.js file. This takes even longer, and seems to reserve much more memory.

After a while, the memory will be released, but subsequent saves of the noonroot.aspx files will cause much larger chunks of memory to be allocated, and the built times have increased by an order of magnitude.

At the extreme, this will lead to an out-of-memory exception and the node process will crash.

This bug seems to only happen when you edit one of the files in the root folder, and is more evident on larger projects where the building times are longer to begin with, and thus the memory 'leak' becomes more apparent faster.

This is harder to reproduce, but from experience, I would argue that this memory 'leak' happens often when you attempt to save a file while the rebuild is still in process. In a larger project, my watcher node process will crash several times a day due to out-of-memory exceptions.

The repository also includes a modified-cli.js that I used for debugging purposes. The modified Tailwind CLI has the addition of logging when the watcher runs the on change handler, and when the promise chain is increased or decreased.

https://user-images.githubusercontent.com/8807171/153777233-54acb464-d31f-4cab-8163-5f035060b85a.mp4

What cannot be seen on the video is the memory usage, which at its peak got up to 4 GB.

FallDownTheSystem avatar Feb 13 '22 22:02 FallDownTheSystem

EDIT: I think it has something to with the content glob matching, because it doesn't seem to slow down with the following tailwind.config.js

module.exports = {
	content: ['./root.aspx', './folder/nonroot.aspx', './folder/nonroot2.aspx']
};

FallDownTheSystem avatar Feb 13 '22 22:02 FallDownTheSystem

I can reproduce the memory usage going up. However, it seems to go back down fairly quickly. I'm not certain that this is something we have any control over (directly or indirectly). I'll make a note to investigate this further to see what we can do here.

Regarding your comment about the glob:

This may be because your glob pattern caused it to scan node_modules looking for .aspx files. Depending on your disk speed, the size of node_modules, computer load, etc… this could be 100ms+ of work just looking for files. This could be contributing to the chain issue but I'm not certain. Given that you discovered you're not seeing issues without the root glob I suggest naming any files in the root and then using glob for only the folders you know you need to scan. That would look something like this:

module.exports = {
    content: ['./root.aspx', './folder/**/*.aspx']
};

thecrypticace avatar Feb 14 '22 19:02 thecrypticace

Thanks for looking into this. I think not scanning the node_modules folder is solid advice 😄

And yes, the memory usage does seem to go back down, but not all the way. I just tested again and after spamming a while it stays around 300-400 MB, and a single save after that spikes the memory usage to 1.6GB, and the build takes 750ms, though I'd argue this is actually longer, 750ms is only for the measured part. For reference, originally the node process takes 50-70 MB and a build takes 30ms.

Here's a video of a single save after having spammed the saves for a while. You can see it start at 400 MB, spikes to 1.6 GB but after it comes down it goes to 460MB and stays there.

https://user-images.githubusercontent.com/8807171/153954099-4c56026f-123d-4bb1-a0b4-66b915588a9d.mp4

I also think (but am not sure) that these kinds of memory leaks or degradations in performance can happen even when you don't do the ridiculous spamming, or have it scan folders with tens of thousands of files.

I wasn't able to figure out where the memory usage is actually increasing, it's possible it's in one of the libraries the CLI calls.

FallDownTheSystem avatar Feb 14 '22 22:02 FallDownTheSystem

Also clearly this is not a widespread issue and is mostly mitigated by not doing anything too dumb, like scanning node_modules, so feel free to close to the issue if you feel it's not worth pursuing.

FallDownTheSystem avatar Feb 14 '22 22:02 FallDownTheSystem

I think it's definitely still worth at least looking into but given that it's not more widespread it's lower priority. I tested a setup where I saved the file ~10,000 times and the process never grew by more than ~20MB-ish in overall usage after it went back down. Might be worth me just letting something run over and over for 15–30m in the background to see what happens.

thecrypticace avatar Feb 14 '22 22:02 thecrypticace

I was testing this by spam saving the tailwind.config.js itself, which produces the same result basically.

One thing I noticed is that these lines:

https://github.com/tailwindlabs/tailwindcss/blob/db475be6ddf087ff96cc326e891ac125d4f9e4e8/src/cli.js#L763-L772

should probably be inside the chain callback. Now they're being called every time the watcher runs (when editing a context dependency). Having made that change to the CLI, it mitigated the issue further, and the memory usage seems to drop down to the normals levels < 100 MB, even after peaking at above 1GB. Subsequent saves are also fast, but spam saving becomes immediately slow still, although the slowness recovers much faster after I stop spamming saves, so something's still afoot.

I'm not sure what, but either some other code runs, besides the watcher's on change handler, or there's something async that's not being awaited, or the method of chaining promises by chain = chain.then(... is not safe.

FallDownTheSystem avatar Feb 14 '22 23:02 FallDownTheSystem

The behavior still happens, even if the watcher event handlers are empty, so this seems to be an issue with chokidar. That said, moving the lines I mentioned above inside the chain is still probably a good idea.

FallDownTheSystem avatar Feb 15 '22 14:02 FallDownTheSystem

I use tailwind in a SvelteKit setup and noticed a similar memory leak. After dumping the heap and looking at it, you can see a lot of older instances of the compilation still hanging around (I ran global.gc() before to make sure). MacOS 12.3 (Intel) / node 16.14.1 and tailwindcss 3.0.23:

Screen Shot 2022-03-17 at 3 54 49 PM

jbergstroem avatar Mar 17 '22 18:03 jbergstroem

We also run the CLI in watch mode on Windows and notice it occasionally running out of memory and crashing Node. It's infrequent enough that I haven't bothered to report it previously, so perhaps the problem is more widespread than might be inferred from the number of GH issues.

We also see a gradual increase in duplicate content output to the .css file over many compiles which we clean-up by stopping the CLI and restarting it - this forces a clean build. Clearly there is some kind of state that can hang-around in the CLI between compiles in some circumstances. Unfortunately it's completely impractical for me to provide a repro URL for this.

willdean avatar Mar 23 '22 22:03 willdean

We are facing the same issue, memory leaks once add something to the content option.

iMuFeng avatar Aug 19 '22 06:08 iMuFeng

Same problem here. I don't think I'm doing anything dumb. My project isn't even particularly big, but after about 20 minutes of saving files, tailwindcss slows down to a crawl.

philiparvidsson avatar Aug 21 '22 10:08 philiparvidsson

I keep updating tailwind to css if it solves this problem. After a while It generates a message of out of memory error. I'm not starting it anymore when I know that I'm not going to use it, which is not ideal.

geraldodev avatar Aug 22 '22 13:08 geraldodev

I was testing this by spam saving the tailwind.config.js itself, which produces the same result basically.

One thing I noticed is that these lines:

https://github.com/tailwindlabs/tailwindcss/blob/db475be6ddf087ff96cc326e891ac125d4f9e4e8/src/cli.js#L763-L772

should probably be inside the chain callback. Now they're being called every time the watcher runs (when editing a context dependency). Having made that change to the CLI, it mitigated the issue further, and the memory usage seems to drop down to the normals levels < 100 MB, even after peaking at above 1GB. Subsequent saves are also fast, but spam saving becomes immediately slow still, although the slowness recovers much faster after I stop spamming saves, so something's still afoot.

I'm not sure what, but either some other code runs, besides the watcher's on change handler, or there's something async that's not being awaited, or the method of chaining promises by chain = chain.then(... is not safe.

I still think this would at least alleviate the problem. The refreshConfig and all the rest should be called within the callback, so that they're properly initialized when the actual rebuild happens. Most of the time this is a nonissue, but when things start slowing down, these can get out of sync.

FallDownTheSystem avatar Aug 22 '22 14:08 FallDownTheSystem

Turns out we were essentially doubling the rule cache (not quite but close enough) instead of just adding the few entries to it that needed to be added. This can result in a significant slow down in fairly specific situations.

I'm hoping this has fixed a good portion of the issue here. Can some of you please give our insiders build a test and see if it helps out at all? I'm hopeful it'll have some positive impact but if it isn't sufficient I'll reopen this issue.

Thanks for all the help and bearing with us on this one. ✨

thecrypticace avatar Aug 29 '22 18:08 thecrypticace

Same problem here. I don't think I'm doing anything dumb. My project isn't even particularly big, but after about 20 minutes of saving files, tailwindcss slows down to a crawl.

I have the same issue on windows, but on a Mac M1 Pro is working fine I don't know if this related to the OS

Siumauricio avatar Mar 12 '23 04:03 Siumauricio

After running tailwindcss in watch mode for a while, it slowed down and I got memory allocation failure:

<--- Last few GCs --->

[29476:0000024319ED0720] 28911888 ms: Scavenge 4035.7 (4124.6) -> 4031.3 (4141.6) MB, 15.0 / 0.0 ms  (average mu = 0.799, current mu = 0.414) allocation failure
[29476:0000024319ED0720] 28916345 ms: Mark-sweep 4045.2 (4141.6) -> 4033.7 (4146.4) MB, 4417.1 / 8.3 ms  (average mu = 0.541, current mu = 0.062) allocation failure scavenge might not succeed     


<--- JS stacktrace --->

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
 1: 00007FF762A779CF v8::internal::CodeObjectRegistry::~CodeObjectRegistry+114207
 2: 00007FF762A06096 DSA_meth_get_flags+65542
 3: 00007FF762A06F4D node::OnFatalError+301
 4: 00007FF76333B1EE v8::Isolate::ReportExternalAllocationLimitReached+94
 5: 00007FF7633257CD v8::SharedArrayBuffer::Externalize+781
 6: 00007FF7631C8B9C v8::internal::Heap::EphemeronKeyWriteBarrierFromCode+1468
 7: 00007FF7631C5CB4 v8::internal::Heap::CollectGarbage+4244
 8: 00007FF7631C3630 v8::internal::Heap::AllocateExternalBackingStore+2000
 9: 00007FF7631E81B6 v8::internal::Factory::NewFillerObject+214
10: 00007FF762F1A685 v8::internal::DateCache::Weekday+1797
11: 00007FF7633C8EE1 v8::internal::SetupIsolateDelegate::SetupHeap+494417
12: 00007FF7633C9DE9 v8::internal::SetupIsolateDelegate::SetupHeap+498265
13: 000002431BCBD93E

Looooong avatar Aug 31 '23 18:08 Looooong

@Looooong did you manage to solve it?

pySilver avatar Oct 14 '23 00:10 pySilver

@pySilver Sadly, no. Even if I use tailwind with postcss, I still get allocation failure after certain amount of file updates.

Looooong avatar Oct 14 '23 15:10 Looooong

@Looooong actually I've managed to solve my issues after few weeks of being angry with constant crashes. In my case it was rogue tailwind plugin that generated excessive amount of classes. On a small project it wasn't an issue but on a larger codebase it became nightmare. Maybe you have something similar. My silly plugin caused enormous slowdowns and memory leaks. Once fixed, everything became smooth and steady with node memory consumption around 2G

pySilver avatar Oct 14 '23 15:10 pySilver

@thecrypticace Using v3.3.2 on linux this still seems to be very much an issue. The easiest way to reproduce is to trigger a significant number of file events by doing something like find . --name "*.html" | xargs touch.

The best solution, if unsatisfying, for me was to just add --poll to my cli invocation.

It would appear that the watcher is not coalescing events unless polling is turned on.

belevy avatar Oct 19 '23 20:10 belevy

@belevy I'll take a look. Can you tell me what OS you're running on, the rough number of files that you're working with (find . -name "*.html" | wc -l), and especially if in Windows+WSL if your files are under /mnt/{drive_letter}?

thecrypticace avatar Oct 19 '23 21:10 thecrypticace

@Looooong actually memory leak is still there. Like you said - after few updates my node process get bigger and bigger up until it gets killed. It can easily exceed 4-5G. Im thinking about disabling all the plugins and monitor memory usage then. I'm not sure if Vitejs can also be an issue here.

pySilver avatar Oct 20 '23 11:10 pySilver

We're having problems with this on Windows running the watcher with npx. After about 30 or so cycles the memory runs away crazily and node gives up. I had a brief go at running it with the Chrome debugger and the problem was some kind of closure leak which I think originated in the node filesystem stuff. I can try and collect that information again.

willdean avatar Oct 20 '23 13:10 willdean

- system: `"x86_64-linux"`
- host os: `Linux 5.15.86, NixOS, 22.11 (Raccoon), 22.11.1629.2f9fd351ec3`

and this was with 26 files in my templates directory but I also have 105 other files being watch that weren't changing.

I would say i probably ran my touch command 3-4 times before slow down and maybe another 5 before it crashed. So on the order of a couple hundered file system events.

There appears to be a memory leak related to this im seeing an addition 100-200mb of memory usage per time i run the find/touch

belevy avatar Oct 20 '23 21:10 belevy

At first, the CLI process consumes around 1GB of RAM with about 30MB of heap. Triggering file watcher multiple times doesn't allocate any significant heap memory.

After a while, the process memory consumption suddenly climbs rapidly, at around 10-20MB/s, up to 10GB.

Screenshot 2023-10-21 171136

Looooong avatar Oct 21 '23 10:10 Looooong

After digging into the source code, the culprit seems to be the package chokidar that is used for file watching. Serveral issues on the package's repo are addressing memory leaking:

  • paulmillr/chokidar#1271
  • paulmillr/chokidar#1275

Probably, this is a bug with chokidar or tailwindcss doesn't use it properly.

Looooong avatar Oct 21 '23 10:10 Looooong

I'm not using single wildcards but I have negative rules to exclude some directories.

pySilver avatar Oct 24 '23 02:10 pySilver

@Looooong looks like a negative match has some impact too. I have a lot of data migrations that I don't want to watch or parse for classes so my tailwind config looks like this:

  content: [
    './static/src/site/**/*.js',
    './project/**/*.{py,jinja2,js}',
    // Temporarily disabled to check if the memory leak is related to this
    // '!/project/**/migrations/**/*',
  ],

Commenting this out helps a little but it is not a complete remedy. In the beginning, the node process uses around 1GB of memory, and after a couple of saves of the same file (typical workflow) memory usage increases up to 3GB+. It doesn't get any lower and slowly getting bigger.

pySilver avatar Oct 25 '23 15:10 pySilver

Things like **/*.js or **/*.tsx are wildcards. I have a few of these things in my content. I managed to take a heap snapshot of the process when the memory reaches 10GB. The heap is around 2GB. Inside the heap, there is a FSWatcher object that is 700MB.

Looooong avatar Oct 25 '23 18:10 Looooong

@Looooong Finally, I fixed my issues by being very specific in what I'm watching using the content option. I've had a few large directories such as icons and migrations in the path where desired files reside. Despite no changes in these files, it somehow causes huge memory issues on subsequent observed file saves. Funny because svg files weren't even observed! It is far from the ideal solution for larger projects but it works for me. Memory does not increase over 700 MB now after 20+ saves. Previously it was already in 4GB or more at that point. I didn't bother using paths without wildcards. I just made more specific to omit huge directories.

pySilver avatar Nov 01 '23 03:11 pySilver