How to avoid nix.gc deleting so many .drv?

Help
1

I have both nix.gc and system.autoUpgrade in my config. Since i change channels to unstable and then downgraded to 22.05, rebuilding the system takes 5 to 6hs when before the upgrade it took 30 mins. After looking at journalctl it seems all the extra time comes from building derivations.

journalctl nixos-upgrade-start

Aug 15 15:13:44 nixos nixos-upgrade-start[2124]: unpacking channels…
Aug 15 15:18:37 nixos nixos-upgrade-start[2350]: this derivation will be built:
Aug 15 15:18:37 nixos nixos-upgrade-start[2350]: /nix/store/1k18pby940bqhhpqsw2g4jx2bjg4v59b-nixos-rebuild.drv
Aug 15 15:18:37 nixos nixos-upgrade-start[2350]: these 62 paths will be fetched (22.88 MiB download, 98.33 MiB unpacked):
Aug 15 15:18:37 nixos nixos-upgrade-start[2350]: /nix/store/241wqj205mi8k1irhhqy6dykf6wkjjcj-libxml2-2.9.14
[…]
Aug 15 15:18:37 nixos nixos-upgrade-start[2350]: /nix/store/zcqghi24zydhw4vlvkjph9ajd1jdsrsl-aws-c-mqtt-0.7.10
Aug 15 15:18:37 nixos nixos-upgrade-start[2350]: copying path ‘/nix/store/jipwzfdgqzhl78di7dijpg9sy51mr0fa-busybox-static-x86_64-unknown-linux-musl-1.35.0’ from ‘https://cache.nixos.org’…
[…]
Aug 15 15:35:00 nixos nixos-upgrade-start[2350]: copying path ‘/nix/store/ycfm401dvky813n4bym8byaywnvigdkl-nix-2.8.1’ from ‘https://cache.nixos.org’…
Aug 15 15:36:43 nixos nixos-upgrade-start[2350]: building ‘/nix/store/1k18pby940bqhhpqsw2g4jx2bjg4v59b-nixos-rebuild.drv’…
Aug 15 15:36:45 nixos nixos-upgrade-start[2121]: building Nix…
Aug 15 15:36:51 nixos nixos-upgrade-start[2121]: building the system configuration…
Aug 15 15:38:58 nixos nixos-upgrade-start[2797]: these 313 derivations will be built:
Aug 15 15:38:58 nixos nixos-upgrade-start[2797]: /nix/store/01gkpd6g4f4xgbzwa44wr7f4zfpv420c-login.pam.drv
[…]
Aug 15 15:38:58 nixos nixos-upgrade-start[2797]: /nix/store/fzinka9b44spf7qydf6r5j3kdjjh57l4-nixos-system-nixos-22.05.2467.879121648fe.drv
Aug 15 15:38:58 nixos nixos-upgrade-start[2797]: these 995 paths will be fetched (1556.86 MiB download, 5194.29 MiB unpacked):
Aug 15 15:38:58 nixos nixos-upgrade-start[2797]: /nix/store/00258sdrq4q75370bb9b5rgsxlj4zr3c-phonon-4.11.1
[…]
Aug 15 15:38:58 nixos nixos-upgrade-start[2797]: /nix/store/zzvpdkxlp0s2c03nfv8c0c0jyprrs4lk-libXScrnSaver-1.2.3
Aug 15 15:38:58 nixos nixos-upgrade-start[2797]: copying path ‘/nix/store/fqmdxlbk32miazamkyavwwiwkn146i37-glibc-locales-2.34-210’ from ‘https://cache.nixos.org’…
[…]

It appears the cause is nix.gc deleting thus .drv files.

journalctl nix-gc-start

Aug 17 15:19:41 nixos systemd[1]: Started nix-gc.timer.
Aug 17 15:19:41 nixos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg=‘unit=nix-gc comm=“systemd” exe="/nix/store/dyxmql05ykvhgipv29l0vkq9xrcsxh0s-systemd-250.4/lib/systemd/systemd" hostname=? addr=? terminal=? res=success’
Aug 17 15:19:57 nixos nix-gc-start[746]: removing old generations of profile /nix/var/nix/profiles/per-user/root/channels
Aug 17 15:19:58 nixos nix-gc-start[746]: removing old generations of profile /nix/var/nix/profiles/per-user/user/channels
Aug 17 15:19:58 nixos nix-gc-start[746]: removing old generations of profile /nix/var/nix/profiles/per-user/user/home-manager
Aug 17 15:19:58 nixos nix-gc-start[746]: removing old generations of profile /nix/var/nix/profiles/per-user/user/profile
Aug 17 15:19:58 nixos nix-gc-start[746]: removing old generations of profile /nix/var/nix/profiles/system
Aug 17 15:20:01 nixos nix-gc-start[746]: finding garbage collector roots…
Aug 17 15:20:04 nixos nix-gc-start[746]: removing stale link from ‘/nix/var/nix/gcroots/auto/5gbrjlq08gww1wglczl5wk56dxpakd6d’ to ‘/tmp/nix-build-4073-0/result’
Aug 17 15:20:04 nixos nix-gc-start[746]: removing stale link from ‘/nix/var/nix/gcroots/auto/bjyh1idsi7xh7zkh6pa7mzi62ic16g52’ to ‘/tmp/nixos-rebuild.ePLe4o/nix’
Aug 17 15:20:04 nixos nix-gc-start[746]: removing stale link from ‘/nix/var/nix/gcroots/auto/08khgc2b3dj8l6ihfyz35cl6ip5i1dqk’ to ‘/tmp/nixos-rebuild.ePLe4o/nix.drv’
Aug 17 15:20:15 nixos nix-gc-start[746]: deleting garbage…
Aug 17 15:20:48 nixos nix-gc-start[746]: deleting ‘/nix/store/1a09bfrdyws875d1gvsqj6a1d06m4b5z-unit-logrotate.timer’
[…]
Aug 17 15:21:30 nixos nix-gc-start[746]: deleting ‘/nix/store/npayscb3nx6dg7p9yqr1r9nw84b73ncq-pcsclite-1.9.5’
Aug 17 15:21:31 nixos nix-gc-start[746]: deleting ‘/nix/store/nndfba3n97sf8kbjh3ailbq5fm57m6j5-nixos-system-nixos-22.05.2485.3d47bbaa26e.drv’
[…] (long list of .drv files)
Aug 17 15:31:24 nixos nix-gc-start[746]: deleting ‘/nix/store/0lby7bkx96lf202pq967x0fbim4xfhim-source.drv’
Aug 17 15:31:24 nixos nix-gc-start[746]: deleting unused links…
Aug 17 15:35:32 nixos nix-gc-start[746]: note: currently hard linking saves 211.84 MiB
Aug 17 15:35:51 nixos nix-gc-start[746]: 3942 store paths deleted, 1620.05 MiB freed
Aug 17 15:35:52 nixos systemd[1]: nix-gc.service: Deactivated successfully.
Aug 17 15:35:52 nixos systemd[1]: nix-gc.service: Consumed 9.297s CPU time, read 166.1M from disk, written 149.1M to disk, no IP traffic.

How do i solve this?

2

What have been the exact steps you used to upgrade/downgrade channels? And where exactly points your current channel to?

1 Like
3

Previous to the upgrade in my config i had system.autoUpgrade.channel = https://nixos.org/channels/nixos-21.11; then i changed it to system.autoUpgrade.channel = https://nixos.org/channels/nixos-22.05; then to system.autoUpgrade.channel = https://nixos.org/channels/nixos-unstable;, then again to system.autoUpgrade.channel = https://nixos.org/channels/nixos-22.05;.

all of this while having

sudo nix-channel --list
nixos https://nixos.org/channels/nixos-21.11

now i have removed system.autoUpgrade.channel from my config and i use

sudo nix-channel --list
nixos https://nixos.org/channels/nixos-22.05

The thing i dont remember is if i manually ran sudo nixos-rebuild switch --upgrade or i let system.autoUpgrade do it automatically. Probably a combination of both.
https://nixos.org/manual/nixos/stable/#sec-upgrading-automatic

4

I don’t know anything about autoupgrading, I never was a friend of the introduced randomness…

Anyway… The channel looks legitimate to me.

There shouldn’t happen much of massive rebuilds, and from a first glance on your logs, you seem to have some initial eval phase causing rebuild of 62 oathes which can be fetched from substitutes/cache.

A roughly 25 MiB download, taking 20 minutes before the actual system building begins. Perhaps you should try to get rid of the IFD here first to and also take a look which path to fetch takes longest.

3 Likes
5

perhaps try either or both of

  keep-outputs = true
  keep-derivations = true

in nix.extraOptions?

(note, they’re text lines not typed values in this case)

3 Likes
6

.drv files are tiny and easily regenerated. They just describe how to do a build, they don’t require a build to create. Deleting them isn’t why things are taking a long time. What takes time is the actual builds they describe, whose outputs are not being deleted.

The interesting question is why so many long-build-time paths are not being loaded from the cache, and without understanding your config, I can’t tell you whether that’s normal or not.

3 Likes
7 
{ config, pkgs, ... }:

{
  imports =
    [
      ./hardware.nix
    ];

  boot.loader = {
    systemd-boot.enable = true;
    efi.canTouchEfiVariables = true;
  };

  time.timeZone = "";

  networking = {
    networkmanager.enable = true;
    useDHCP = false;
    interfaces.enp2s0.useDHCP = true;
    hostName = "";
  };

  i18n.defaultLocale = "";
  console = {
    font = "Lat2-Terminus16";
    keyMap = "";
  };

  services.xserver = {
    layout = "";
    enable = true;
    desktopManager.plasma5.enable = true;
    displayManager.sddm = {
      enable = true;
      autoNumlock = true;
    };
  };

  sound.enable = true;
  hardware.pulseaudio.enable = true;

  users.mutableUsers = false;
  users.users = {
    root = {
      hashedPassword = "";
    };
    "" = {
      isNormalUser = true;
      extraGroups = [ "wheel" "networkmanager" ];
      hashedPassword = "";
    };
  };

  swapDevices = [
    { device = "/.swapfile"; }
  ];

  services.emacs = {
    enable = true;
    package = import ./emacs.nix { inherit pkgs; };
  };

  environment = {
    variables = {
      EDITOR = "emacsclient -c";
    };
    shellAliases = {
      emacs="emacsclient -c";
    };
  };

 nix.nixPath = [
    "nixpkgs=/nix/var/nix/profiles/per-user/root/channels/nixos"
    "nixos-config=/home/user/Nixos/configuration.nix"
    "/nix/var/nix/profiles/per-user/root/channels"
  ];

  system.autoUpgrade = {
    enable = true;
    dates = "13:00";
  };

  nix.gc = {
    automatic = true;
    dates = "13:15";
    options = "-d";
  };

  nix.autoOptimiseStore = true;

  environment.systemPackages = with pkgs; [
    firefox
    mpv
    gnupg
    keepassxc
    syncthing
    libsForQt5.ark
    git
    restic
  ];

  nix.allowedUsers = [ "root" ];

  security.sudo.extraConfig = "Defaults rootpw";

  security.pam.services =
    let accountRequiredTime = pkgs.lib.mkDefault ( pkgs.lib.mkAfter "account required pam_time.so" );
    in {
      login.text = accountRequiredTime;
      sddm.text = accountRequiredTime;
      sudo.text = accountRequiredTime;
      su.text = accountRequiredTime;
    };

  environment.etc."security/time.conf".text =
    ''
    sudo|su;*;*;Al0600-1900
    login|sddm;*;*;Al0600-1930
    '';

  system.stateVersion = "21.05";
}
8

What’s in that file?

1 Like
9 
{ pkgs ? import <nixpkgs> {} }:

let
  myEmacs = pkgs.emacs;
  emacsWithPackages = (pkgs.emacsPackagesFor myEmacs).emacsWithPackages;
in
emacsWithPackages
  (epkgs: (with epkgs.melpaStablePackages; [
  ]) ++ (with epkgs.melpaPackages; [
    nix-mode
    zerodark-theme
    sudo-edit
  ]) ++ (with epkgs.elpaPackages; [
  ]) ++ (with pkgs; [
  ]))
11 
# Do not modify this file!  It was generated by ‘nixos-generate-config’
# and may be overwritten by future invocations.  Please make changes
# to /etc/nixos/configuration.nix instead.
{ config, lib, pkgs, modulesPath, ... }:

{
  imports =
    [ (modulesPath + "/installer/scan/not-detected.nix")
    ];

  boot.initrd.availableKernelModules = [ "ehci_pci" "ata_piix" "usb_storage" "sd_mod" "sr_mod" ];
  boot.initrd.kernelModules = [ ];
  boot.kernelModules = [ ];
  boot.extraModulePackages = [ ];

  fileSystems."/" =
    { device = "/dev/disk/by-uuid/07a0741a-6182-499d-ae7d-2f914e4ce04e";
      fsType = "ext4";
    };

  fileSystems."/boot" =
    { device = "/dev/disk/by-uuid/91D3-E366";
      fsType = "vfat";
    };

  swapDevices = [ ];

}
12

No IFD here. I think that was a red herring. What the 22M download actually was, is the Nix build of the Nix package manager itself before the NixOS closure. nixos-rebuild does that by default in non---fast mode.

What is significant is that these two units ran at about the same time.

It’s possible them running concurrently caused them to congested each other’s IO making both much slower than half the available disk speed.

What’s your hardware and internet speed like? Slow internet speed + slow hardware could very well cause this to take longer than expected.

Where did you get the 5-6h number from? That’s insanely long.

GC has nothing to do with this though, it only ran for 15min.

1 Like
13

Ouch… Haven’t used nixos-rebuild in non --flake mode for quite a while… I was not aware that such a thing happens, even though it makes sense.

1 Like
14

I think this might be the problem, i change my internet provider and a couple of weeks later, after upgrading to unstable, i started noticing the problem.
According to speedtest I have 36.23Mbps download and 5ms idle latency, I ran sudo nixos-rebuild switch and it took less than 30mins to complete. If the rebuild takes too long again I will check with speedtest if I have internet problems.

That’s what i remember it took to complete the rebuild after i manually run sudo nixos-rebuild switch a couple of weeks ago.
But looking at the logs i found this, it took 4.5hs and didn’t even finish:

Jul 04 15:00:18 nixos systemd[1]: Starting NixOS Upgrade...
Jul 04 15:08:00 nixos nixos-upgrade-start[1767]: this derivation will be built:
Jul 04 15:08:00 nixos nixos-upgrade-start[1767]:   /nix/store/nyllxzqhakx8n8d1za8njw1gvp5rhkqm-nixos-rebuild.drv
Jul 04 15:08:00 nixos nixos-upgrade-start[1767]: these 29 paths will be fetched (9.67 MiB download, 42.13 MiB unpacked):
Jul 04 15:08:00 nixos nixos-upgrade-start[1767]:   /nix/store/1rrx04im1hi1zznrbm9kcvdfzgcrccw4-aws-c-mqtt-0.7.10
[...]
Jul 04 15:11:34 nixos nixos-upgrade-start[1767]: building '/nix/store/nyllxzqhakx8n8d1za8njw1gvp5rhkqm-nixos-rebuild.drv'...
Jul 04 15:11:35 nixos nixos-upgrade-start[1764]: building Nix...
Jul 04 15:11:37 nixos nixos-upgrade-start[1764]: building the system configuration...
Jul 04 15:12:54 nixos nixos-upgrade-start[1904]: these 192 derivations will be built:
Jul 04 15:12:55 nixos nixos-upgrade-start[1904]:   /nix/store/nb1ksmjyfn4is3sj0sqybbrzxp0iqghc-builder.pl.drv
[...]
Jul 04 15:12:55 nixos nixos-upgrade-start[1904]:   /nix/store/zz67018pv5l196zdxz7snqhy0hp5jqc1-e2fsprogs-1.46.5-info
Jul 04 15:12:56 nixos nixos-upgrade-start[1904]: copying path '/nix/store/zi9vngbjvqqgrb2jh97vx58ax92rclhh-linux-5.15.49' from 'https://cache.nixos.org'...
[...]
Jul 04 18:35:19 nixos nixos-upgrade-start[1904]: copying path '/nix/store/fd66kbayg2qkyy9zzr5w9dg3v7sw0wxl-kwin-5.24.5' from 'https://cache.nixos.org'...
Jul 04 18:45:14 nixos nixos-upgrade-start[1904]: building '/nix/store/mq8l0s5p8dz5x2zplil7gz28p1n746ak-Xsetup.drv'...
[...]
Jul 04 19:17:18 nixos nixos-upgrade-start[1904]: building '/nix/store/idgg2sbggkyw66zfh8x1nc00f4k9vq29-unit-emacs.service.drv'...
Jul 04 19:30:03 nixos systemd[1]: nixos-upgrade.service: Main process exited, code=killed, status=15/TERM
Jul 04 19:31:06 nixos nixos-upgrade-start[1904]: error: interrupted by the user
Jul 04 19:31:07 nixos systemd[1]: nixos-upgrade.service: Failed with result 'signal'.
Jul 04 19:31:07 nixos systemd[1]: Stopped NixOS Upgrade.
Jul 04 19:31:07 nixos systemd[1]: nixos-upgrade.service: Consumed 4min 52.359s CPU time, received 1.3G IP traffic, sent 34.8M IP traffic.

Also, upgrading to unstable took 10hs

Jun 21 17:00:07 nixos systemd[1]: Starting NixOS Upgrade...
Jun 21 17:05:16 nixos nixos-upgrade-start[3843]: unpacking 'https://nixos.org/channels/nixos-unstable/nixexprs.tar.xz'...
Jun 21 18:12:28 nixos nixos-upgrade-start[3843]: these derivations will be built:
Jun 21 18:12:34 nixos nixos-upgrade-start[3843]:   /nix/store/h95xb704rgc008zm005wjp6ib65s0j6p-nixos-rebuild.drv
Jun 21 18:12:34 nixos nixos-upgrade-start[3843]: these paths will be fetched (23.28 MiB download, 105.80 MiB unpacked):
[...]
Jun 21 19:14:46 nixos nixos-upgrade-start[4908]: these 314 derivations will be built:
[...]
Jun 21 19:14:49 nixos nixos-upgrade-start[4908]: these 1022 paths will be fetched (1871.04 MiB download, 6342.03 MiB unpacked):
[...]
Jun 22 02:54:33 nixos nixos[17593]: finished switching to system configuration /nix/store/a60rq3nihm35q4nf7b7gghlk5gn7my72-nixos-system-nixos-22.11pre386636.0d68d7c857f
Jun 22 02:54:34 nixos systemd[1]: nixos-upgrade.service: Deactivated successfully.
Jun 22 02:54:34 nixos systemd[1]: Finished NixOS Upgrade.
Jun 22 02:54:34 nixos systemd[1]: nixos-upgrade.service: Consumed 7min 10.603s CPU time, read 2.8G from disk, written 6.7G to disk, received 1.9G IP traffic, sent 55.0M IP traffic.
15

Based on the timestamps on those logs, the unexpected time seems to come mostly from downloading, not building: 15:12:56 - 18:45:14 spent downloading, 18:45:14-19:30:03 spent building. An hour building is still rather long though, so I don’t think it’s solely an internet issue. Roughly how powerful is the CPU? How much RAM do you have?

1 Like
16

4g of ram and 4 cores, 4 threads @ 3.1 GHz.

17

That build that failed with SIGTERM, can you look for additional logs indicating why it was killed? ie systemd timeout or more likely OOM killer.

I suspect you’re under a lot of memory pressure, try reducing the parallelism that the nix daemon can use, something like nix.settings.cores = 1

1 Like
18

That’s not a lot of space to do a nixos rebuild in if you’re doing any notable local builds. Like @uep said, I suspect you’re thrashing due to memory pressure.

1 Like
19

cron run shutdown now

i will try it

20

That unfortunately doesn’t tell us much. That could be anything from pretty decent to practically e-waste.

We’ll need the exact CPU model number or at least its generation in addition to that info.

4GB of RAM is quite little though and Nix often needs a surprising amount of memory to do its job. zram swap is recommended with such little system RAM.

What you’ll need to do is run these builds manually to get some proper data. Monitor resource usage while it runs.

Internet speed != Internet speed. It depends on many factors. I’ve had issues with speeds to the CDN powering the cache while other sources worked just fine. In my case it was DNS resolving a less than ideal end-point.

Try curling the direct URL to a larger NAR like

curl 'https://cache.nixos.org/nar/0kx52cfa4iiqzj892g3nxccljvszxwxb24qhql622q6f75i6ja4p.nar.xz' > /dev/null
1 Like
21

Intel Core i5-3340
I didn’t know that, i thought cores and clock speed were the most important. Also, i have an HDD, i don’t know how much write speed is relevant, but it isn’t high.

Like this?
zramSwap.enable = true;

I will try to write a script to log the resource usage so you can see it better, but for now I will describe what I saw in kde system monitor, the ram stays stable at 2.8GiB and the swap at 387MiB, the cpu, when building, stays at an average of 300% and reaches 400% a couple of times, and when downloading the average is 2.1MiB. While doing this rebuild i had nix.settings.cores = 1; and nix.extraOptions = "keep-outputs = true keep-derivations = true"; in my config.
Then when i add zramSwap.enable = true; the only thing different i notice is that the ram, when the building started, decreased to 2.1GiB and the swap increased to 1.3GiB, the average cpu decreased this time (aprox. 250%), but i did build a different package.

  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 56.1M  100 56.1M    0     0  2257k      0  0:00:25  0:00:25 --:--:-- 2459k