nixos/nix
1
1
Fork 0
mirror of https://github.com/NixOS/nix.git synced 2025-11-12 13:36:02 +01:00
Code Activity

libexpr: Use EvalProfiler for FunctionCallTrace

Browse source 
This wires up the {pre,post}FunctionCallHook machinery
in EvalState::callFunction and migrates FunctionCallTrace
to use the new EvalProfiler mechanisms for tracing.

Note that branches when the hook gets called are marked with [[unlikely]]
as a hint to the compiler that this is not a hot path. For non-tracing
evaluation this should be a 100% predictable branch, so the performance
cost is nonexistent.

Some measurements to prove support this point:

```
nix build .#nix-cli
nix build github:nixos/nix/d692729759e4e370361cc5105fbeb0e33137ca9e#nix-cli --out-link before
```

(Before)

```
$ taskset -c 2,3 hyperfine "GC_INITIAL_HEAP_SIZE=16g before/bin/nix eval nixpkgs#gnome --no-eval-cache" --warmup 4
Benchmark 1: GC_INITIAL_HEAP_SIZE=16g before/bin/nix eval nixpkgs#gnome --no-eval-cache
  Time (mean ± σ):      2.517 s ±  0.032 s    [User: 1.464 s, System: 0.476 s]
  Range (min … max):    2.464 s …  2.557 s    10 runs
```

(After)

```
$ taskset -c 2,3 hyperfine "GC_INITIAL_HEAP_SIZE=16g result/bin/nix eval nixpkgs#gnome --no-eval-cache" --warmup 4
Benchmark 1: GC_INITIAL_HEAP_SIZE=16g result/bin/nix eval nixpkgs#gnome --no-eval-cache
  Time (mean ± σ):      2.499 s ±  0.022 s    [User: 1.448 s, System: 0.478 s]
  Range (min … max):    2.472 s …  2.537 s    10 runs
```
This commit is contained in:
Sergei Zimmerman 2025-05-16 22:29:18 +00:00
parent 6b4a86a9e3
commit fa6f69f9c5
No known key found for this signature in database
GPG key ID: A9B0B557CA632325
4 changed files with 38 additions and 13 deletions
Download patch file Download diff file Expand all files Collapse all files

12
src/libexpr/function-trace.cc
View file

@ -3,16 +3,20 @@
namespace nix {
FunctionCallTrace::FunctionCallTrace(const Pos & pos) : pos(pos) {
void FunctionCallTrace::preFunctionCallHook(
const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
{
auto duration = std::chrono::high_resolution_clock::now().time_since_epoch();
auto ns = std::chrono::duration_cast<std::chrono::nanoseconds>(duration);
printMsg(lvlInfo, "function-trace entered %1% at %2%", pos, ns.count());
printMsg(lvlInfo, "function-trace entered %1% at %2%", state.positions[pos], ns.count());
}
FunctionCallTrace::~FunctionCallTrace() {
void FunctionCallTrace::postFunctionCallHook(
const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
{
auto duration = std::chrono::high_resolution_clock::now().time_since_epoch();
auto ns = std::chrono::duration_cast<std::chrono::nanoseconds>(duration);
printMsg(lvlInfo, "function-trace exited %1% at %2%", pos, ns.count());
printMsg(lvlInfo, "function-trace exited %1% at %2%", state.positions[pos], ns.count());
}
}