facebook / buck2

Build system, successor to Buck
https://buck2.build/
Apache License 2.0
3.53k stars 215 forks source link

daemon startup is a bit slow #507

Open rbtcollins opened 10 months ago

rbtcollins commented 10 months ago

I took an existing Bazel monorepo I work on and started experimenting with BUCK as a learning exercise. I was quite surprised that the daemon takes ~5 seconds to startup:

time buck2 clean && time buck2 targets ...
killing buckd server
Buck2 daemon pid 2029993 has exited
/PATHTOREPO/buck-out/v2/gen
/PATHTOREPO/buck-out/v2/log
/PATHTOREPO/buck-out/v2/tmp
/PATHTOREPO/buck-out/v2/forkserver
/home/robertc/.buck/buckd//PATHTOREPO/v2

real    0m0.175s
user    0m0.018s
sys     0m0.023s
Build ID: de17d116-cd54-4890-b50c-bbbbb15da49d
Jobs completed: 8. Time elapsed: 0.3s.
root//:hello_world

real    0m4.994s
user    0m0.006s
sys     0m0.035s

The repo is very modest in size:

time find . >& /dev/null

real    0m0.161s
user    0m0.018s
sys     0m0.144s

Even forcing a device check - so statting:

time du -x >& /dev/null

real    0m0.237s
user    0m0.013s
sys     0m0.224s

It is obviously not a terrible thing - 5 seconds once a while - but it is a surprise given the emphasis on speed in the documentation.

ndmitchell commented 10 months ago

That is a lot longer than expected! I assume this is Linux? If you do buck2 log whatran does it give any clues? If you up the verbosity does it suggest anything? On a mobile so can't time anything, but expecting 0.1s kind of time range.

zjturner commented 10 months ago

Ive noticed this on windows as well, although my repo is a decent size. My immediate reaction was that it’s probably synchronously statting every file in the tree, but I didn’t take any steps to confirm or deny

jhdub23 commented 10 months ago

How many files are in your repo? This may be related to buck2 + inotify having to start watching all of the files within your repo. See #465. Our initial startup time was hours (I ended up letting it run overnight, so I don't have a more exact figure).

rbtcollins commented 10 months ago

@ndmitchell Linux yes.

Just switched to my buck2 branch again after working on other stuff. So this is entirely clean.

time buck2 clean && time buck2 targets ...
no buckd server running
/PATH/buck-out/v2/log
/PATH/v2

real    0m0.030s
user    0m0.004s
sys     0m0.034s
Build ID: 681f277a-98c5-44d1-97e8-61f60260a7bd
Jobs completed: 4. Time elapsed: 0.4s.
root//:hello_world

real    0m33.577s
user    0m0.011s
sys     0m0.032s
:PATH$ buck2 log whatran 
Showing commands from: buck2 targets ...
:PATH$ find .  | wc -l
39593
rbtcollins commented 10 months ago

On the inotify performance - I'd need to write a test to be sure, but my intuition is that cannot be the cause - there are only 6K directories present:

find . -type d | wc -l
6267

Thats a small number of watches to create in my experience.

ndmitchell commented 9 months ago

That is indeed way too slow. How long does buck2 server take as that spawns just the server? What about buck2 targets which should output zero targets?

avdv commented 8 months ago

I am on Linux too and experience the same problem.

$ find .  | wc -l
2366
$ time buck2 server
[2024-01-15T09:25:10.959+01:00] Waiting on buck2 daemon ecd95896-036f-4d0b-be57-a874b50c72d2...
buckd.endpoint=tcp:35185

________________________________________________________
Executed in   13.82 secs      fish           external
   usr time   81.55 millis   43.49 millis   38.06 millis
   sys time   43.54 millis    8.09 millis   35.45 millis

$ time buck2 targets
Build ID: 44846436-ca35-4856-9381-9d28e083fdef
Jobs completed: 2. Time elapsed: 0.0s.

________________________________________________________
Executed in   78.09 millis    fish           external
   usr time   19.43 millis  269.00 micros   19.16 millis
   sys time   17.18 millis   34.00 micros   17.15 millis

Now, I noticed there is a node_modules directory symlink which was created by Bazel:

$ find -L . | wc -l
1957914

Running buck2 under strace reveals there are 304893 calls to inotify_add_watch. I guess this could explain it?

\edit: Well, after removing the node_modules symlink, the startup time went down to ~10 seconds. We are also using direnv with nix, which creates a .direnv folder in the project directory by default, symlinking the shell environment from the nix store. Following https://github.com/direnv/direnv/wiki/Customizing-cache-location to relocate the folder the startup time is now down to a few hundred msecs.