Capture Nix stats during eval

[grahamc]

It would be great to track the Nix evaluation stats over time. An example of these stats are as follows:

grahamc@Morbo> export NIX_SHOW_STATS=1 NIX_COUNT_CALLS=0; cp ../ofborg/ofborg/src/outpaths.nix .; nix-env -f ./outpaths.nix -qaP --no-name --out-path --arg checkMeta true > outs
evaluation statistics:
  time elapsed: 113.927
  size of a value: 24
  size of an attr: 24
  environments allocated: 51021608 (1605585144 bytes)
  list elements: 84838642 (678709136 bytes)
  list concatenations: 5012224
  values allocated: 144000479 (3456011496 bytes)
  sets allocated: 14772174 (4559741232 bytes)
  right-biased unions: 7603556
  values copied in right-biased unions: 130009211
  symbols in symbol table: 288036
  size of symbol table: 11669838
  number of thunks: 97110210
  number of thunks avoided: 85959307
  number of attr lookups: 44963046
  number of primop calls: 35071263
  number of function calls: 45204301
  total allocations: 10300047008 bytes
  current Boehm heap size: 8598323200 bytes
  total Boehm heap allocations: 13792084256 bytes

However, to avoid some ad-hoc parsing of this data, it would be nice if this information could be written out to a separate file, perhaps provided by an environment variable, like NIX_WRITE_STATS=/tmp/nix-eval-stats.

Additionally, it would be cool if it was a bit more simple:

  time elapsed: 113.927
  size of a value: 24
  size of an attr: 24
  environments allocated count: 51021608
  environments allocated bytes: 1605585144
  list elements count: 84838642
  list elements bytes: 678709136
  list concatenations: 5012224
  values allocated count: 144000479
  values allocated bytes: 3456011496
  sets allocated count: 14772174
  sets allocated bytes: 4559741232
  right-biased unions: 7603556
  values copied in right-biased unions: 130009211
  symbols in symbol table: 288036
  size of symbol table: 11669838
  number of thunks: 97110210
  number of thunks avoided: 85959307
  number of attr lookups: 44963046
  number of primop calls: 35071263
  number of function calls: 45204301
  total allocations: 10300047008 bytes
  current Boehm heap size bytes: 8598323200
  total Boehm heap allocations bytes: 13792084256

The code is here: https://github.com/NixOS/nix/blob/master/src/libexpr/eval.cc#L1700

[vcunat]

We have https://hydra.nixos.org/job/nixpkgs/trunk/metrics#tabs-charts

[grahamc]

Yeah, I'd like to say exactly how a PR changed nixpkgs's evaluation stats during evaluation time. This way we can spot big increases, and celebrate decreases. I suppose I could look at how Hydra captures this data.

[vcunat]

Oh, right, even before merging :-) Timings might not be stable enough, but the counts should be sufficient to spot significant regressions.

[grahamc]

This all started, btw, because I had to bump the initial heap from the default to 4g the other day, and I'd like to catch future big jumps before ofborg is suddenly failing on master.