nix icon indicating copy to clipboard operation
nix copied to clipboard

Collect build time statistics

Open lheckemann opened this issue 7 years ago • 10 comments

I've often found myself wanting to know how long a derivation took to build. The closest I've found to this has been using stat /nix/var/log/nix/drvs/xx/xx[…]-foo-bar.drv and subtracting the atime from the mtime. This is very brittle, however, and I think it would be nice for nix to record this information somewhere. Does this perhaps already exist? Any thoughts on the idea or implementation?

lheckemann avatar Dec 02 '17 17:12 lheckemann

Hydra does collect build duration, but how to use it? https://hydra.nixos.org/build/90102549

Duration: | 17s

But we don't know number of cores, parallelism and CPU frequency of builder machine. Maybe user-time collection would be great here, as building is usually CPU intensive, and other subsystems are not very loaded.

Local collector would be also great, for both successful builds and failed ones.

danbst avatar Mar 08 '19 07:03 danbst

Yes, collecting stats like user+sys time is the best suggestion so far. I doubt there's something noticeably better that's easy to do, at least in the way Hydra.nixos.org looks (quite diverse).

EDIT: for good usability, we'd need to think of API exposing such meta-data via binary cache. Then nix build might even show ETA :rainbow:

vcunat avatar Mar 08 '19 11:03 vcunat

Some other statistics that might be useful:

  • max disk usage (might be able to get away with only measuring disk usage at the end, but maybe some build systems delete intermediate files before the end? in that case, we'd need to regularly measure)
    • would allow us to warn and/or offer to run GC if there's insufficient space to build something
  • max memory usage
  • lines/bytes of build output
    • assuming that builds spew out logs at a roughly constant rate, this would let us make a decent guess at an ETA even on machines faster/slower than Hydra

Gaelan avatar May 13 '20 21:05 Gaelan

I love the last idea! To be a bit more precise, you could actually annotate every output line with a timestamp and then with the benefit of hindsight say "after 10% of the build time the builder hat produced 1000 lines". That would cover the case where for example the actual build is relatively quiet but the install phase spews a lot of information.

timokau avatar May 14 '20 11:05 timokau

It would be very useful if that information was attached to the .narinfo file.

zimbatm avatar May 15 '20 17:05 zimbatm

I marked this as stale due to inactivity. → More info

stale[bot] avatar Feb 13 '21 20:02 stale[bot]

I'm still interested in this happening

anka-213 avatar Feb 16 '21 11:02 anka-213

I marked this as stale due to inactivity. → More info

stale[bot] avatar Aug 17 '21 02:08 stale[bot]

Annoying bot; this is important.

ncfavier avatar Dec 20 '21 08:12 ncfavier

This could probably be bolted on using the pre-build-hook and post-build-hook options.

lheckemann avatar Jan 25 '22 21:01 lheckemann

This issue has been mentioned on NixOS Discourse. There might be relevant details there:

https://discourse.nixos.org/t/measure-elapsed-time-in-phases-successful-or-not/21161/1

nixos-discourse avatar Aug 22 '22 20:08 nixos-discourse

@fricklerhandwerk I don't see how this is related to error messages?

lheckemann avatar Sep 26 '22 18:09 lheckemann

Probably a random mistake, I went through issues fairly quickly.

fricklerhandwerk avatar Sep 28 '22 07:09 fricklerhandwerk