devenv test takes over a minute to run. Is this expected behavior?

[sylvesterroos]

Given this devenv.nix:

{
  pkgs,
  lib,
  config,
  inputs,
  ...
}:

let
  system = pkgs.stdenv.system;

  # for when devenv-nixpkgs doesn't have a newly released package
  pkgs-unstable = import inputs.nixpkgs-unstable { inherit system; };

  beamPkgs = pkgs-unstable.beam.packagesWith pkgs-unstable.beam.interpreters.erlang_27;
  elixir = beamPkgs.elixir_1_18;
in
{
  dotenv.enable = false;

  packages =
    with pkgs;
    [
      # Downloading certain dependencies
      git

      # Phoenix assets
      nodejs_22

      # Viewing devenv processes
      process-compose
    ]
    ++
      # phoenix_live_reload + ExUnit Notifier
      (
        # Linux only
        lib.optionals stdenv.isLinux (
          with pkgs;
          [
            inotify-tools
            libnotify
          ]
        )
        ++
          # macOS only
          lib.optionals stdenv.isDarwin (
            with pkgs;
            [
              terminal-notifier
              darwin.apple_sdk.frameworks.CoreFoundation
              darwin.apple_sdk.frameworks.CoreServices
            ]
          )
      );

  languages.elixir = {
    enable = true;
    package = elixir;
  };

  services.postgres = {
    enable = (config.container.isBuilding) == false;
    package = pkgs.postgresql_17;
    listen_addresses = "0.0.0.0,::";
    port = 5432;
    initialDatabases = [ { name = "postgres"; } ];
    initialScript = ''
      CREATE ROLE postgres WITH LOGIN PASSWORD 'postgres' SUPERUSER;
    '';
  };

  tasks = {
    "db:start" = {
      exec = "devenv processes up -d postgres";
    };

    "db:stop" = {
      exec = "process-compose --unix-socket=${config.process.managers.process-compose.unixSocket.path} process stop postgres";
    };
  };

  # See full reference at https://devenv.sh/reference/options/
}

It takes over a minute to run devenv test:

.test.sh

set -e

wait_for_port 5432 30
mix test

`devenv test` output

❯ time devenv test
• Overriding .devenv to .devenv.CtVrAGcyrmu5
• Building tests ...
• Using Cachix: devenv
these 5 derivations will be built:
  /nix/store/ardlw1hf5lygzv0q7c3n2kjql1ac81k2-postgresql.conf.drv
  /nix/store/ysg5pyql803aw4xidnnfr6k8qxnhhy69-setup-postgres.drv
  /nix/store/8r6q5pfnismxrzzwivhs4y64jkdm4hwd-start-postgres.drv
  /nix/store/0kzyn4wrwzhns9w965cjdmfx0f54dj37-devenv-profile.drv
  /nix/store/w2ncdslmz07xsp4qqyqm49p2i3qg1iya-devenv-test.drv
building '/nix/store/ardlw1hf5lygzv0q7c3n2kjql1ac81k2-postgresql.conf.drv'
building '/nix/store/ysg5pyql803aw4xidnnfr6k8qxnhhy69-setup-postgres.drv'
building '/nix/store/8r6q5pfnismxrzzwivhs4y64jkdm4hwd-start-postgres.drv'
building '/nix/store/0kzyn4wrwzhns9w965cjdmfx0f54dj37-devenv-profile.drv'
warning: collision between `/nix/store/1mcmns7893i8040dpy5biw2x2g0pis26-postgresql-17.1-dev/bin/pg_config' and `/nix/store/j70pk2jhkv86dlmys0xf5jssacz7f4cd-postgresql-17.1/bin/pg_config'
created 1072 symlinks in user environment
building '/nix/store/w2ncdslmz07xsp4qqyqm49p2i3qg1iya-devenv-test.drv'
✔ Building tests in 25.9s.
• Building processes ...
these 4 derivations will be built:
  /nix/store/1czkkwaqr1jjxy6v6xn3pxcljgkxaa3x-postgres.drv
  /nix/store/vf2jx4fzpaf1nm3s8qh5srq7xdhfsgn5-db-stop.drv
  /nix/store/brd9xjgmy29mg4mmbi9cafgw68sxlcmp-process-compose.yaml.drv
  /nix/store/hmiwzpf1z8b1wg2vbqffncvy02gj4pdb-devenv-up.drv
building '/nix/store/vf2jx4fzpaf1nm3s8qh5srq7xdhfsgn5-db-stop.drv'
building '/nix/store/1czkkwaqr1jjxy6v6xn3pxcljgkxaa3x-postgres.drv'
building '/nix/store/brd9xjgmy29mg4mmbi9cafgw68sxlcmp-process-compose.yaml.drv'
building '/nix/store/hmiwzpf1z8b1wg2vbqffncvy02gj4pdb-devenv-up.drv'
✔ Building processes in 20.9s.
• Starting processes ...
• Building shell ...
building '/nix/store/hbsvl38ihlszpsd5y97lpss4jbmnxaib-devenv-shell-env.drv'
✔ Building shell in 20.2s.
• PID is 258127
• Stop:      $ devenv processes stop
✔ Starting processes in 20.2s.
• Running tests ...
• Building shell ...
✔ Building shell in 0.1s.
Running tasks     devenv:enterShell
Succeeded         devenv:enterShell 12ms
1 Succeeded                         13.49ms

Running tasks     devenv:enterShell
Succeeded         devenv:enterShell 12ms
1 Succeeded                         12.71ms

• Setting up shell environment ...
Running tasks     devenv:enterShell
Succeeded         devenv:enterShell 11ms
1 Succeeded                         12.44ms

• Testing ...
Running tasks     devenv:enterTest
Not implemented   devenv:enterTest
1 Skipped                           57.66µs

• Running .test.sh...
bash: connect: Connection refused
bash: line 1: /dev/tcp/localhost/5432: Connection refused
[postgres       ] The files belonging to this database system will be owned by user "sylvester".
[postgres       ] This user must also own the server process.
[postgres       ]
[postgres       ] The database cluster will be initialized with locale "C".
[postgres       ] The default text search configuration will be set to "english".
[postgres       ]
[postgres       ] Data page checksums are disabled.
[postgres       ]
[postgres       ] creating directory /home/sylvester/Code/ElixirProjects/books/programming-phoenix-liveview/pento/.devenv.CtVrAGcyrmu5/state/postgres ... ok
[postgres       ] creating subdirectories ... ok
[postgres       ] selecting dynamic shared memory implementation ... posix
[postgres       ] selecting default "max_connections" ... 100
[postgres       ] selecting default "shared_buffers" ... 128MB
[postgres       ] selecting default time zone ... Europe/Amsterdam
[postgres       ] creating configuration files ... ok
[postgres       ] running bootstrap script ... ok
bash: connect: Connection refused
bash: line 1: /dev/tcp/localhost/5432: Connection refused
bash: connect: Connection refused
bash: line 1: /dev/tcp/localhost/5432: Connection refused
[postgres       ] performing post-bootstrap initialization ... ok
[postgres       ] initdb: warning: enabling "trust" authentication for local connections
[postgres       ] syncing data to disk ... ok
[postgres       ]
[postgres       ]
[postgres       ] Success. You can now start the database server using:
[postgres       ]
[postgres       ] initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.
[postgres       ]     /nix/store/j70pk2jhkv86dlmys0xf5jssacz7f4cd-postgresql-17.1/bin/pg_ctl -D /home/sylvester/Code/ElixirProjects/books/programming-phoenix-liveview/pento/.devenv.CtVrAGcyrmu5/state/postgres -l logfile start
[postgres       ]
[postgres       ]
[postgres       ] PostgreSQL initdb process complete.
[postgres       ]
[postgres       ]
[postgres       ] PostgreSQL is setting up the initial database.
[postgres       ]
[postgres       ] waiting for server to start....2025-02-09 12:16:03.183 GMT [259788] LOG:  starting PostgreSQL 17.1 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 13.3.0, 64-bit
[postgres       ] 2025-02-09 12:16:03.183 GMT [259788] LOG:  listening on Unix socket "/run/user/1000/devenv-9fb2143/postgres/.s.PGSQL.5432"
[postgres       ] 2025-02-09 12:16:03.197 GMT [259791] LOG:  database system was shut down at 2025-02-09 12:16:02 GMT
[postgres       ] 2025-02-09 12:16:03.208 GMT [259788] LOG:  database system is ready to accept connections
[postgres       ]  done
[postgres       ] server started
[postgres       ] Checking presence of database: postgres
[postgres       ] 0
[postgres       ] Creating database: postgres
[postgres       ] 2025-02-09 12:16:03.272 GMT [259802] ERROR:  database "postgres" already exists
[postgres       ] 2025-02-09 12:16:03.272 GMT [259802] STATEMENT:  CREATE DATABASE "postgres";
[postgres       ] ERROR:  database "postgres" already exists
[postgres       ] CREATE ROLE
[postgres       ] waiting for server to shut down....2025-02-09 12:16:03.299 GMT [259788] LOG:  received fast shutdown request
[postgres       ] 2025-02-09 12:16:03.302 GMT [259788] LOG:  aborting any active transactions
[postgres       ] 2025-02-09 12:16:03.306 GMT [259788] LOG:  background worker "logical replication launcher" (PID 259794) exited with exit code 1
[postgres       ] 2025-02-09 12:16:03.306 GMT [259789] LOG:  shutting down
[postgres       ] 2025-02-09 12:16:03.309 GMT [259789] LOG:  checkpoint starting: shutdown immediate
bash: connect: Connection refused
bash: line 1: /dev/tcp/localhost/5432: Connection refused
[postgres       ] 2025-02-09 12:16:03.333 GMT [259789] LOG:  checkpoint complete: wrote 7 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.007 s, sync=0.006 s, total=0.028 s; sync files=6, longest=0.004 s, average=0.001 s; distance=3 kB, estimate=3 kB; lsn=0/14EB6B0, redo lsn=0/14EB6B0
[postgres       ] 2025-02-09 12:16:03.343 GMT [259788] LOG:  database system is shut down
[postgres       ]  done
[postgres       ] server stopped
[postgres       ] 2025-02-09 12:16:03.439 GMT [259767] LOG:  starting PostgreSQL 17.1 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 13.3.0, 64-bit
[postgres       ] 2025-02-09 12:16:03.439 GMT [259767] LOG:  listening on IPv4 address "0.0.0.0", port 5432
[postgres       ] 2025-02-09 12:16:03.443 GMT [259767] LOG:  listening on IPv6 address "::", port 5432
[postgres       ] 2025-02-09 12:16:03.443 GMT [259767] LOG:  listening on Unix socket "/run/user/1000/devenv-9fb2143/postgres/.s.PGSQL.5432"
[postgres       ] 2025-02-09 12:16:03.454 GMT [259810] LOG:  database system was shut down at 2025-02-09 12:16:03 GMT
[postgres       ] 2025-02-09 12:16:03.464 GMT [259767] LOG:  database system is ready to accept connections
[postgres       ] 2025-02-09 12:16:03.834 GMT [259815] LOG:  incomplete startup packet
Running ExUnit with seed: 946512, max_cases: 32

.........................................................................................................[postgres      ] 2025-02-09 12:16:07.364 GMT [259894] ERROR:  duplicate key value violates unique constraint "users_tokens_context_token_index"
[postgres       ] 2025-02-09 12:16:07.364 GMT [259894] DETAIL:  Key (context, token)=(session, \x32f56d6e8032b2fd18052a17012a67f4c9a6f034082a7973cf317e147fd79486) already exists.
[postgres       ] 2025-02-09 12:16:07.364 GMT [259894] STATEMENT:  INSERT INTO "users_tokens" ("context","token","user_id","inserted_at") VALUES ($1,$2,$3,$4) RETURNING "id"
.....................................
Finished in 1.6 seconds (1.0s async, 0.5s sync)
142 tests, 0 failures
✔ Running tests in 7.4s.
• Stopping process with PID 258127
• Tests passed :)
Stopping processes...
[postgres       ] 2025-02-09 12:16:07.690 GMT [259767] LOG:  received fast shutdown request
[postgres       ] 2025-02-09 12:16:07.690 GMT [259767] LOG:  could not open file "postmaster.pid": No such file or directory
[postgres       ] 2025-02-09 12:16:07.690 GMT [259767] LOG:  aborting any active transactions
[postgres       ] 2025-02-09 12:16:07.693 GMT [259767] LOG:  background worker "logical replication launcher" (PID 259813) exited with exit code 1
[postgres       ] 2025-02-09 12:16:07.694 GMT [259808] LOG:  shutting down
[postgres       ] 2025-02-09 12:16:07.700 GMT [259808] LOG:  checkpoint starting: shutdown immediate
[postgres       ] 2025-02-09 12:16:07.701 GMT [259808] FATAL:  could not open directory "pg_logical/snapshots": No such file or directory
[postgres       ] 2025-02-09 12:16:07.703 GMT [259767] LOG:  checkpointer process (PID 259808) exited with exit code 1
[postgres       ] 2025-02-09 12:16:07.703 GMT [259767] LOG:  terminating any other active server processes
[postgres       ] 2025-02-09 12:16:07.703 GMT [259767] LOG:  abnormal database system shutdown
[postgres       ] 2025-02-09 12:16:07.715 GMT [259767] LOG:  database system is shut down
Processes stopped.

________________________________________________________
Executed in   76.73 secs    fish           external
   usr time   50.78 secs    0.00 micros   50.78 secs
   sys time   16.05 secs  806.00 micros   16.05 secs

This is despite the environment being ready to use before running test, thanks to direnv.

[emdneto]

I'm facing some scenarios using go which is taking 5m to run devenv ci