devenv icon indicating copy to clipboard operation
devenv copied to clipboard

Devenv builds and initializations are slow

Open SamoylovMD opened this issue 10 months ago • 15 comments

Describe the bug I am facing an issue with devenv shell overall performance. Running devenv shell right after devenv init (no other changes in the code) takes really long time, ~1 minute usually. Moreover, the time is the same on each run. This behaviour is the same for my real projects.

Related Discord thread

To reproduce

  1. Create a new empty folder and change to it
  2. Run devenv init
  3. Run devenv shell and wait for initialization
  4. Exit from shell and run devenv shell again

Version

➜ devenv-test-3 devenv version devenv 1.0.2 (x86_64-darwin) ➜ devenv-test-3 direnv --version 2.34.0 ➜ devenv-test-3 cachix --version cachix 1.7 ➜ devenv-test-3 nix --version nix (Nix) 2.21.0

MacOS Sonoma 14.3, Intel-based, zsh.

Logs

devenv.log

SamoylovMD avatar Apr 05 '24 11:04 SamoylovMD

Do you have SSD?

domenkozar avatar Apr 06 '24 14:04 domenkozar

@domenkozar Yes, I also can provide some other hardware stats if it helps

SamoylovMD avatar Apr 06 '24 17:04 SamoylovMD

Can you pass -v to devenv and paste the logs?

domenkozar avatar Apr 08 '24 06:04 domenkozar

Here it is:

➜  devenv-test-3  devenv -v shell
• Building shell ...
• Using Cachix: devenv
• Running command: nix --show-trace --extra-experimental-features nix-command --extra-experimental-features flakes --option warn-dirty false --option eval-cache false --keep-going --max-jobs 6 print-dev-env --profile /Users/maksims/tmp/devenv-test-3/.devenv/gc/shell --option extra-substituters https://devenv.cachix.org --option extra-trusted-public-keys devenv.cachix.org-1:w1cLUi8dv3hnoSPGAuibQv+f9TZLr6cv/Hm9XgU50cw=
• Creating symlink /nix/store/mkf4rrcqpahfb2m1z7y8y4mhahpmdr30-devenv-shell-env -> /Users/maksims/.local/share/devenv/gc/1712571332.248852000-shell
✔ Building shell in 40.6s.
• Entering shell
• Running command: nix --show-trace --extra-experimental-features nix-command --extra-experimental-features flakes --option warn-dirty false --option eval-cache false --keep-going --max-jobs 6 develop /Users/maksims/tmp/devenv-test-3/.devenv/gc/shell
✨ devenv 1.0.2 is out of date. Please update to 1.0.3: https://devenv.sh/getting-started/#installation
hello from devenv
git version 2.43.2

I noticed that it downloaded some tar.gz from NixOS github for a very long time (~5-10 minutes or so), while the size of a file was around 40Mb, which with my network bandwidth should have been downloaded in less than 1 second. But other stages are slow too.

SamoylovMD avatar Apr 08 '24 10:04 SamoylovMD

What happens if you run nix --show-trace --extra-experimental-features nix-command --extra-experimental-features flakes --option warn-dirty false --option eval-cache false --keep-going --max-jobs 6 print-dev-env --profile /Users/maksims/tmp/devenv-test-3/.devenv/gc/shell --option extra-substituters https://devenv.cachix.org --option extra-trusted-public-keys devenv.cachix.org-1:w1cLUi8dv3hnoSPGAuibQv+f9TZLr6cv/Hm9XgU50cw= and how long does it take?

domenkozar avatar Apr 13 '24 12:04 domenkozar

@domenkozar I executed the command as-is, and it printed:

path '/Users/maksims/tmp/devenv-test-3' does not contain a 'flake.nix', searching up error: could not find a flake.nix file

SamoylovMD avatar Apr 16 '24 12:04 SamoylovMD

You need to run it in the same directory.

domenkozar avatar Apr 17 '24 08:04 domenkozar

Same with what exactly? I ran the command in the root directory of my project with devenv:

(devenv) prgm-msamoilov2:devenv-test-3 maksims$ pwd /Users/maksims/tmp/devenv-test-3 (devenv) prgm-msamoilov2:devenv-test-3 maksims$ ls -la total 36 drwxr-xr-x 11 maksims staff 352 Apr 5 13:17 . drwxr-xr-x 13 maksims staff 416 Apr 15 16:52 .. drwxr-xr-x 9 maksims staff 288 Apr 5 13:02 .devenv -rw-r--r-- 1 maksims staff 5146 Apr 8 12:14 .devenv.flake.nix drwxr-xr-x 4 maksims staff 128 Apr 5 13:05 .direnv -rw-r--r-- 1 maksims staff 176 Apr 5 13:02 .envrc -rw-r--r-- 1 maksims staff 91 Apr 5 13:02 .gitignore -rw-r--r-- 1 maksims staff 4028 Apr 5 13:02 devenv.lock -rw-r--r-- 1 maksims staff 5082 Apr 5 13:17 devenv.log -rw-r--r-- 1 maksims staff 749 Apr 5 13:02 devenv.nix -rw-r--r-- 1 maksims staff 341 Apr 5 13:02 devenv.yaml (devenv) prgm-msamoilov2:devenv-test-3 maksims$ nix --show-trace --extra-experimental-features nix-command --extra-experimental-features flakes --option warn-dirty false --option eval-cache false --keep-going --max-jobs 6 print-dev-env --profile /Users/maksims/tmp/devenv-test-3/.devenv/gc/shell --option extra-substituters https://devenv.cachix.org --option extra-trusted-public-keys devenv.cachix.org-1:w1cLUi8dv3hnoSPGAuibQv+f9TZLr6cv/Hm9XgU50cw= path '/Users/maksims/tmp/devenv-test-3' does not contain a 'flake.nix', searching up error: could not find a flake.nix file

SamoylovMD avatar Apr 17 '24 11:04 SamoylovMD

I see >20s init times on an M2 macbook pro running macos 13.6.7 when enabling support for python.

Here is the flake.nix that takes 20s to init:

{
  inputs = {
   nixpkgs.url = "github:NixOS/nixpkgs/nixos-23.11";
    devenv.url = "github:cachix/devenv";
    nixpkgs-python.url = "github:cachix/nixpkgs-python";
  };

  nixConfig = {
    extra-trusted-public-keys = [
      "devenv.cachix.org-1:w1cLUi8dv3hnoSPGAuibQv+f9TZLr6cv/Hm9XgU50cw="
    ];
    extra-substituters = [
      "https://devenv.cachix.org"
    ];
  };

  outputs = { self, nixpkgs, devenv,  ... }@inputs:
    let
      system = "aarch64-darwin";
      pkgs = nixpkgs.legacyPackages.${system};
    in
    {
      packages.${system}.devenv-up = self.devShells.${system}.default.config.procfileScript;

      devShells.${system}.default = devenv.lib.mkShell {
        inherit inputs pkgs;
        modules = [
          ({ pkgs, config, ... }: {
              name = "cooler";

              # bash shell script executed when devenv shell entered
              enterShell = ''
                echo "devenv shell for $PROJECT"
              '';

              # https://devenv.sh/basics/
              env = {
                PROJECT = "cooler";
              };


              # https://devenv.sh/languages/
              languages.python = {
                enable = true;
              };

              # https://devenv.sh/scripts/
              scripts = {
                hello.exec = "echo \"hello from $PROJECT\"";
              };
            })];
          };
    };
}

if I set languages.python.enable=false; or remove the languages expression, then it inits in <2s.

When I run nix develop --impure -vvv . it seems to spend more than 10s after printing the line:

evaluating file '/nix/store/i6yzq14z49ayjinw6v9v06kqz62akkay-source/modules/hook.nix'

enabling other languages, eg, languages.nix.enable = true; does not cause the slow init time.

john-g-g avatar May 31 '24 22:05 john-g-g

Chiming in here, devenv's slowness right now is the big issue preventing me from rolling it out to the rest of the team. I really enjoy using it but it probably took me 10x longer to chain up our service-based architecture than it should have, as the feedback loop was so long. It was fairly agonizing if I realized I forgot an env var because it cost about 60s of time on every mistake.

Running devenv 1.0.8 using a devenv.nix file, not using flake-parts or flakes for this particular project so similar to @SamoylovMD the command above fails as I don't have a flake.nix file. Running on an M3 Pro.

devenv shell --verbose:

• Building shell ...
• Using Cachix: devenv
• Running command: /nix/store/z1zrijdcxzx5a8yf4prggamg6k41hcmi-nix-2.21-devenv/bin/nix --show-trace --extra-experimental-features nix-command --extra-experimental-features flakes --option warn-dirty false --keep-going --max-jobs 4 --option eval-cache false print-dev-env --profile /Users/xxx/Code/function/.devenv/gc/shell --option extra-substituters https://devenv.cachix.org --option extra-trusted-public-keys devenv.cachix.org-1:w1cLUi8dv3hnoSPGAuibQv+f9TZLr6cv/Hm9XgU50cw= nixpkgs-python.cachix.org-1:hxjI7pFxTyuTHn2NkvWCrAUcNZLNS3ZAvfYNuYifcEU=
• Creating symlink /nix/store/0cxqya4z0y19b5kvnxrx15dqhm4kr7gm-devenv-shell-env -> /Users/xxx/.local/share/devenv/gc/1725122347.93600000-shell
✔ Building shell in 14.7s.
• Entering shell
• Running command: /nix/store/z1zrijdcxzx5a8yf4prggamg6k41hcmi-nix-2.21-devenv/bin/nix --show-trace --extra-experimental-features nix-command --extra-experimental-features flakes --option warn-dirty false --keep-going --max-jobs 4 --option eval-cache false develop /Users/xxx/Code/function/.devenv/gc/shell

Runs were:

  • 22s
  • 14s
  • 11s

... to build shell with no changes in-between. Then if I run devenv up, it takes on average about 25 seconds with no changes for the process-compose shell to appear:

• Building processes ...
• Using Cachix: devenv
✔ Building processes in 8.5s.
• Starting processes ...
• Building shell ...
✔ Building shell in 7.4s.

... after those two Building shell in xx s statements, it takes about another 10 seconds for process-compose to appear. I'm similarly using Python.

Happy to run whatever helps debug.

SirensOfTitan avatar Aug 31 '24 16:08 SirensOfTitan

@SirensOfTitan see this workaround to at least avoid the devenv up invocation altogether: https://github.com/cachix/devenv/issues/756#issuecomment-1807860259

This makes the process-compose.yml file evaluation eager on devenv shell invoke, which is negligible. Then you can avoid any further evals via process-compose up.

thenonameguy avatar Aug 31 '24 17:08 thenonameguy

@SirensOfTitan we're aware this is important and we're working on changes that will run sub 50ms for all commands if nothing changes in your Nix environment.

Curious though, is this on macOS?

domenkozar avatar Sep 03 '24 18:09 domenkozar

Curious though, is this on macOS?

I see the same behaviour--devenv shell takes between 30s to 45s on each run. I'm on macOS 13.6, MacBook Pro with SSD.

venkytv avatar Sep 04 '24 12:09 venkytv

Curious though, is this on macOS?

It is! In particular it's Sonoma 14.5.

SirensOfTitan avatar Sep 14 '24 12:09 SirensOfTitan

I recently switched to M2-based Macbook and updated to latest macos 14.5, the overall shell activation is much faster but I think it's more related to M2 chip performance. By "faster" I mean ~2x faster.

There are still frequent rebuilds though.

Also, if you add new scripts but don't change packages or anything else, is it supposed to trigger rebuilds?

SamoylovMD avatar Sep 14 '24 12:09 SamoylovMD