Skip to content

Commit 4777734

Browse files
Mic92Mic92
authored
Merge pull request #13261 from xokdvium/eval-profiler-derivations
libexpr: Include derivation names in the call stack profile
2 parents 543cee1 + 9e97eca commit 4777734

File tree

8 files changed

+112
-63
lines changed

8 files changed

+112
-63
lines changed

‎src/libexpr/eval-profiler.cc

Lines changed: 68 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -5,18 +5,14 @@
55

66
namespace nix {
77

8-
void EvalProfiler::preFunctionCallHook(
9-
const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
10-
{
11-
}
8+
void EvalProfiler::preFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) {}
129

13-
void EvalProfiler::postFunctionCallHook(
14-
const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
10+
void EvalProfiler::postFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
1511
{
1612
}
1713

1814
void MultiEvalProfiler::preFunctionCallHook(
19-
const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
15+
EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
2016
{
2117
for (auto & profiler : profilers) {
2218
if (profiler->getNeededHooks().test(Hook::preFunctionCall))
@@ -25,7 +21,7 @@ void MultiEvalProfiler::preFunctionCallHook(
2521
}
2622

2723
void MultiEvalProfiler::postFunctionCallHook(
28-
const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
24+
EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
2925
{
3026
for (auto & profiler : profilers) {
3127
if (profiler->getNeededHooks().test(Hook::postFunctionCall))
@@ -99,6 +95,14 @@ struct FunctorFrameInfo
9995
auto operator<=>(const FunctorFrameInfo & rhs) const = default;
10096
};
10197

98+
struct DerivationStrictFrameInfo
99+
{
100+
PosIdx callPos = noPos;
101+
std::string drvName;
102+
std::ostream & symbolize(const EvalState & state, std::ostream & os, PosCache & posCache) const;
103+
auto operator<=>(const DerivationStrictFrameInfo & rhs) const = default;
104+
};
105+
102106
/** Fallback frame info. */
103107
struct GenericFrameInfo
104108
{
@@ -107,7 +111,8 @@ struct GenericFrameInfo
107111
auto operator<=>(const GenericFrameInfo & rhs) const = default;
108112
};
109113

110-
using FrameInfo = std::variant<LambdaFrameInfo, PrimOpFrameInfo, FunctorFrameInfo, GenericFrameInfo>;
114+
using FrameInfo =
115+
std::variant<LambdaFrameInfo, PrimOpFrameInfo, FunctorFrameInfo, DerivationStrictFrameInfo, GenericFrameInfo>;
111116
using FrameStack = std::vector<FrameInfo>;
112117

113118
/**
@@ -125,8 +130,10 @@ class SampleStack : public EvalProfiler
125130
return Hooks().set(preFunctionCall).set(postFunctionCall);
126131
}
127132

133+
FrameInfo getPrimOpFrameInfo(const PrimOp & primOp, std::span<Value *> args, PosIdx pos);
134+
128135
public:
129-
SampleStack(const EvalState & state, std::filesystem::path profileFile, std::chrono::nanoseconds period)
136+
SampleStack(EvalState & state, std::filesystem::path profileFile, std::chrono::nanoseconds period)
130137
: state(state)
131138
, sampleInterval(period)
132139
, profileFd([&]() {
@@ -140,23 +147,22 @@ class SampleStack : public EvalProfiler
140147
}
141148

142149
[[gnu::noinline]] void
143-
preFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
150+
preFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
144151
[[gnu::noinline]] void
145-
postFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
152+
postFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
146153

147154
void maybeSaveProfile(std::chrono::time_point<std::chrono::high_resolution_clock> now);
148155
void saveProfile();
149-
FrameInfo getFrameInfoFromValueAndPos(const Value & v, PosIdx pos);
156+
FrameInfo getFrameInfoFromValueAndPos(const Value & v, std::span<Value *> args, PosIdx pos);
150157

151158
SampleStack(SampleStack &&) = default;
152159
SampleStack & operator=(SampleStack &&) = delete;
153160
SampleStack(const SampleStack &) = delete;
154161
SampleStack & operator=(const SampleStack &) = delete;
155162
~SampleStack();
156-
157163
private:
158164
/** Hold on to an instance of EvalState for symbolizing positions. */
159-
const EvalState & state;
165+
EvalState & state;
160166
std::chrono::nanoseconds sampleInterval;
161167
AutoCloseFD profileFd;
162168
FrameStack stack;
@@ -167,15 +173,41 @@ class SampleStack : public EvalProfiler
167173
PosCache posCache;
168174
};
169175

170-
FrameInfo SampleStack::getFrameInfoFromValueAndPos(const Value & v, PosIdx pos)
176+
FrameInfo SampleStack::getPrimOpFrameInfo(const PrimOp & primOp, std::span<Value *> args, PosIdx pos)
177+
{
178+
auto derivationInfo = [&]() -> std::optional<FrameInfo> {
179+
/* Here we rely a bit on the implementation details of libexpr/primops/derivation.nix
180+
and derivationStrict primop. This is not ideal, but is necessary for
181+
the usefulness of the profiler. This might actually affect the evaluation,
182+
but the cost shouldn't be that high as to make the traces entirely inaccurate. */
183+
if (primOp.name == "derivationStrict") {
184+
try {
185+
/* Error context strings don't actually matter, since we ignore all eval errors. */
186+
state.forceAttrs(*args[0], pos, "");
187+
auto attrs = args[0]->attrs();
188+
auto nameAttr = state.getAttr(state.sName, attrs, "");
189+
auto drvName = std::string(state.forceStringNoCtx(*nameAttr->value, pos, ""));
190+
return DerivationStrictFrameInfo{.callPos = pos, .drvName = std::move(drvName)};
191+
} catch (...) {
192+
/* Ignore all errors, since those will be diagnosed by the evaluator itself. */
193+
}
194+
}
195+
196+
return std::nullopt;
197+
}();
198+
199+
return derivationInfo.value_or(PrimOpFrameInfo{.expr = &primOp, .callPos = pos});
200+
}
201+
202+
FrameInfo SampleStack::getFrameInfoFromValueAndPos(const Value & v, std::span<Value *> args, PosIdx pos)
171203
{
172204
/* NOTE: No actual references to garbage collected values are not held in
173205
the profiler. */
174206
if (v.isLambda())
175207
return LambdaFrameInfo{.expr = v.payload.lambda.fun, .callPos = pos};
176-
else if (v.isPrimOp())
177-
return PrimOpFrameInfo{.expr = v.primOp(), .callPos = pos};
178-
else if (v.isPrimOpApp())
208+
else if (v.isPrimOp()) {
209+
return getPrimOpFrameInfo(*v.primOp(), args, pos);
210+
} else if (v.isPrimOpApp())
179211
/* Resolve primOp eagerly. Must not hold on to a reference to a Value. */
180212
return PrimOpFrameInfo{.expr = v.primOpAppPrimOp(), .callPos = pos};
181213
else if (state.isFunctor(v)) {
@@ -190,10 +222,10 @@ FrameInfo SampleStack::getFrameInfoFromValueAndPos(const Value & v, PosIdx pos)
190222
return GenericFrameInfo{.pos = pos};
191223
}
192224

193-
[[gnu::noinline]] void SampleStack::preFunctionCallHook(
194-
const EvalState & state, const Value & v, [[maybe_unused]] std::span<Value *> args, const PosIdx pos)
225+
[[gnu::noinline]] void
226+
SampleStack::preFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
195227
{
196-
stack.push_back(getFrameInfoFromValueAndPos(v, pos));
228+
stack.push_back(getFrameInfoFromValueAndPos(v, args, pos));
197229

198230
auto now = std::chrono::high_resolution_clock::now();
199231

@@ -208,9 +240,8 @@ FrameInfo SampleStack::getFrameInfoFromValueAndPos(const Value & v, PosIdx pos)
208240
}
209241

210242
[[gnu::noinline]] void
211-
SampleStack::postFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
243+
SampleStack::postFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
212244
{
213-
214245
if (!stack.empty())
215246
stack.pop_back();
216247
}
@@ -251,6 +282,18 @@ std::ostream & PrimOpFrameInfo::symbolize(const EvalState & state, std::ostream
251282
return os;
252283
}
253284

285+
std::ostream &
286+
DerivationStrictFrameInfo::symbolize(const EvalState & state, std::ostream & os, PosCache & posCache) const
287+
{
288+
/* Sometimes callsite position can have an unresolved origin, which
289+
leads to confusing «none»:0 locations in the profile. */
290+
auto pos = posCache.lookup(callPos);
291+
if (!std::holds_alternative<std::monostate>(pos.origin))
292+
os << posCache.lookup(callPos) << ":";
293+
os << "primop derivationStrict:" << drvName;
294+
return os;
295+
}
296+
254297
void SampleStack::maybeSaveProfile(std::chrono::time_point<std::chrono::high_resolution_clock> now)
255298
{
256299
if (now - lastDump >= profileDumpInterval)
@@ -300,8 +343,7 @@ SampleStack::~SampleStack()
300343

301344
} // namespace
302345

303-
ref<EvalProfiler>
304-
makeSampleStackProfiler(const EvalState & state, std::filesystem::path profileFile, uint64_t frequency)
346+
ref<EvalProfiler> makeSampleStackProfiler(EvalState & state, std::filesystem::path profileFile, uint64_t frequency)
305347
{
306348
/* 0 is a special value for sampling stack after each call. */
307349
std::chrono::nanoseconds period = frequency == 0

‎src/libexpr/eval.cc

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2243,6 +2243,16 @@ bool EvalState::forceBool(Value & v, const PosIdx pos, std::string_view errorCtx
22432243
return v.boolean();
22442244
}
22452245

2246+
Bindings::const_iterator EvalState::getAttr(Symbol attrSym, const Bindings * attrSet, std::string_view errorCtx)
2247+
{
2248+
auto value = attrSet->find(attrSym);
2249+
if (value == attrSet->end()) {
2250+
error<TypeError>("attribute '%s' missing", symbols[attrSym])
2251+
.withTrace(noPos, errorCtx)
2252+
.debugThrow();
2253+
}
2254+
return value;
2255+
}
22462256

22472257
bool EvalState::isFunctor(const Value & fun) const
22482258
{

‎src/libexpr/function-trace.cc

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,15 +4,15 @@
44
namespace nix {
55

66
void FunctionCallTrace::preFunctionCallHook(
7-
const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
7+
EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
88
{
99
auto duration = std::chrono::high_resolution_clock::now().time_since_epoch();
1010
auto ns = std::chrono::duration_cast<std::chrono::nanoseconds>(duration);
1111
printMsg(lvlInfo, "function-trace entered %1% at %2%", state.positions[pos], ns.count());
1212
}
1313

1414
void FunctionCallTrace::postFunctionCallHook(
15-
const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
15+
EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos)
1616
{
1717
auto duration = std::chrono::high_resolution_clock::now().time_since_epoch();
1818
auto ns = std::chrono::duration_cast<std::chrono::nanoseconds>(duration);

‎src/libexpr/include/nix/expr/eval-profiler.hh

Lines changed: 5 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -62,8 +62,7 @@ public:
6262
* @param args Function arguments.
6363
* @param pos Function position.
6464
*/
65-
virtual void
66-
preFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos);
65+
virtual void preFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos);
6766

6867
/**
6968
* Hook called on EvalState::callFunction exit.
@@ -74,8 +73,7 @@ public:
7473
* @param args Function arguments.
7574
* @param pos Function position.
7675
*/
77-
virtual void
78-
postFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos);
76+
virtual void postFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos);
7977

8078
virtual ~EvalProfiler() = default;
8179

@@ -106,12 +104,11 @@ public:
106104
void addProfiler(ref<EvalProfiler> profiler);
107105

108106
[[gnu::noinline]] void
109-
preFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
107+
preFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
110108
[[gnu::noinline]] void
111-
postFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
109+
postFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
112110
};
113111

114-
ref<EvalProfiler>
115-
makeSampleStackProfiler(const EvalState & state, std::filesystem::path profileFile, uint64_t frequency);
112+
ref<EvalProfiler> makeSampleStackProfiler(EvalState & state, std::filesystem::path profileFile, uint64_t frequency);
116113

117114
}

‎src/libexpr/include/nix/expr/eval.hh

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -542,6 +542,11 @@ public:
542542
std::string_view forceString(Value & v, NixStringContext & context, const PosIdx pos, std::string_view errorCtx, const ExperimentalFeatureSettings & xpSettings = experimentalFeatureSettings);
543543
std::string_view forceStringNoCtx(Value & v, const PosIdx pos, std::string_view errorCtx);
544544

545+
/**
546+
* Get attribute from an attribute set and throw an error if it doesn't exist.
547+
*/
548+
Bindings::const_iterator getAttr(Symbol attrSym, const Bindings * attrSet, std::string_view errorCtx);
549+
545550
template<typename... Args>
546551
[[gnu::noinline]]
547552
void addErrorTrace(Error & e, const Args & ... formatArgs) const;

‎src/libexpr/include/nix/expr/function-trace.hh

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -17,9 +17,9 @@ public:
1717
FunctionCallTrace() = default;
1818

1919
[[gnu::noinline]] void
20-
preFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
20+
preFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
2121
[[gnu::noinline]] void
22-
postFunctionCallHook(const EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
22+
postFunctionCallHook(EvalState & state, const Value & v, std::span<Value *> args, const PosIdx pos) override;
2323
};
2424

2525
}

‎src/libexpr/primops.cc

Lines changed: 10 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -670,26 +670,12 @@ struct CompareValues
670670

671671
typedef std::list<Value *, gc_allocator<Value *>> ValueList;
672672

673-
674-
static Bindings::const_iterator getAttr(
675-
EvalState & state,
676-
Symbol attrSym,
677-
const Bindings * attrSet,
678-
std::string_view errorCtx)
679-
{
680-
auto value = attrSet->find(attrSym);
681-
if (value == attrSet->end()) {
682-
state.error<TypeError>("attribute '%s' missing", state.symbols[attrSym]).withTrace(noPos, errorCtx).debugThrow();
683-
}
684-
return value;
685-
}
686-
687673
static void prim_genericClosure(EvalState & state, const PosIdx pos, Value * * args, Value & v)
688674
{
689675
state.forceAttrs(*args[0], noPos, "while evaluating the first argument passed to builtins.genericClosure");
690676

691677
/* Get the start set. */
692-
auto startSet = getAttr(state, state.sStartSet, args[0]->attrs(), "in the attrset passed as argument to builtins.genericClosure");
678+
auto startSet = state.getAttr(state.sStartSet, args[0]->attrs(), "in the attrset passed as argument to builtins.genericClosure");
693679

694680
state.forceList(*startSet->value, noPos, "while evaluating the 'startSet' attribute passed as argument to builtins.genericClosure");
695681

@@ -703,7 +689,7 @@ static void prim_genericClosure(EvalState & state, const PosIdx pos, Value * * a
703689
}
704690

705691
/* Get the operator. */
706-
auto op = getAttr(state, state.sOperator, args[0]->attrs(), "in the attrset passed as argument to builtins.genericClosure");
692+
auto op = state.getAttr(state.sOperator, args[0]->attrs(), "in the attrset passed as argument to builtins.genericClosure");
707693
state.forceFunction(*op->value, noPos, "while evaluating the 'operator' attribute passed as argument to builtins.genericClosure");
708694

709695
/* Construct the closure by applying the operator to elements of
@@ -720,7 +706,7 @@ static void prim_genericClosure(EvalState & state, const PosIdx pos, Value * * a
720706

721707
state.forceAttrs(*e, noPos, "while evaluating one of the elements generated by (or initially passed to) builtins.genericClosure");
722708

723-
auto key = getAttr(state, state.sKey, e->attrs(), "in one of the attrsets generated by (or initially passed to) builtins.genericClosure");
709+
auto key = state.getAttr(state.sKey, e->attrs(), "in one of the attrsets generated by (or initially passed to) builtins.genericClosure");
724710
state.forceValue(*key->value, noPos);
725711

726712
if (!doneKeys.insert(key->value).second) continue;
@@ -1203,7 +1189,7 @@ static void prim_derivationStrict(EvalState & state, const PosIdx pos, Value * *
12031189
auto attrs = args[0]->attrs();
12041190

12051191
/* Figure out the name first (for stack backtraces). */
1206-
auto nameAttr = getAttr(state, state.sName, attrs, "in the attrset passed as argument to builtins.derivationStrict");
1192+
auto nameAttr = state.getAttr(state.sName, attrs, "in the attrset passed as argument to builtins.derivationStrict");
12071193

12081194
std::string drvName;
12091195
try {
@@ -1893,7 +1879,7 @@ static void prim_findFile(EvalState & state, const PosIdx pos, Value * * args, V
18931879
if (i != v2->attrs()->end())
18941880
prefix = state.forceStringNoCtx(*i->value, pos, "while evaluating the `prefix` attribute of an element of the list passed to builtins.findFile");
18951881

1896-
i = getAttr(state, state.sPath, v2->attrs(), "in an element of the __nixPath");
1882+
i = state.getAttr(state.sPath, v2->attrs(), "in an element of the __nixPath");
18971883

18981884
NixStringContext context;
18991885
auto path = state.coerceToString(pos, *i->value, context,
@@ -2782,8 +2768,7 @@ void prim_getAttr(EvalState & state, const PosIdx pos, Value * * args, Value & v
27822768
{
27832769
auto attr = state.forceStringNoCtx(*args[0], pos, "while evaluating the first argument passed to builtins.getAttr");
27842770
state.forceAttrs(*args[1], pos, "while evaluating the second argument passed to builtins.getAttr");
2785-
auto i = getAttr(
2786-
state,
2771+
auto i = state.getAttr(
27872772
state.symbols.create(attr),
27882773
args[1]->attrs(),
27892774
"in the attribute set under consideration"
@@ -2973,13 +2958,13 @@ static void prim_listToAttrs(EvalState & state, const PosIdx pos, Value * * args
29732958
for (auto v2 : args[0]->listItems()) {
29742959
state.forceAttrs(*v2, pos, "while evaluating an element of the list passed to builtins.listToAttrs");
29752960

2976-
auto j = getAttr(state, state.sName, v2->attrs(), "in a {name=...; value=...;} pair");
2961+
auto j = state.getAttr(state.sName, v2->attrs(), "in a {name=...; value=...;} pair");
29772962

29782963
auto name = state.forceStringNoCtx(*j->value, j->pos, "while evaluating the `name` attribute of an element of the list passed to builtins.listToAttrs");
29792964

29802965
auto sym = state.symbols.create(name);
29812966
if (seen.insert(sym).second) {
2982-
auto j2 = getAttr(state, state.sValue, v2->attrs(), "in a {name=...; value=...;} pair");
2967+
auto j2 = state.getAttr(state.sValue, v2->attrs(), "in a {name=...; value=...;} pair");
29832968
attrs.insert(sym, j2->value, j2->pos);
29842969
}
29852970
}
@@ -4224,15 +4209,15 @@ static void prim_convertHash(EvalState & state, const PosIdx pos, Value * * args
42244209
state.forceAttrs(*args[0], pos, "while evaluating the first argument passed to builtins.convertHash");
42254210
auto inputAttrs = args[0]->attrs();
42264211

4227-
auto iteratorHash = getAttr(state, state.symbols.create("hash"), inputAttrs, "while locating the attribute 'hash'");
4212+
auto iteratorHash = state.getAttr(state.symbols.create("hash"), inputAttrs, "while locating the attribute 'hash'");
42284213
auto hash = state.forceStringNoCtx(*iteratorHash->value, pos, "while evaluating the attribute 'hash'");
42294214

42304215
auto iteratorHashAlgo = inputAttrs->get(state.symbols.create("hashAlgo"));
42314216
std::optional<HashAlgorithm> ha = std::nullopt;
42324217
if (iteratorHashAlgo)
42334218
ha = parseHashAlgo(state.forceStringNoCtx(*iteratorHashAlgo->value, pos, "while evaluating the attribute 'hashAlgo'"));
42344219

4235-
auto iteratorToHashFormat = getAttr(state, state.symbols.create("toHashFormat"), args[0]->attrs(), "while locating the attribute 'toHashFormat'");
4220+
auto iteratorToHashFormat = state.getAttr(state.symbols.create("toHashFormat"), args[0]->attrs(), "while locating the attribute 'toHashFormat'");
42364221
HashFormat hf = parseHashFormat(state.forceStringNoCtx(*iteratorToHashFormat->value, pos, "while evaluating the attribute 'toHashFormat'"));
42374222

42384223
v.mkString(Hash::parseAny(hash, ha).to_string(hf, hf == HashFormat::SRI));

0 commit comments

Comments
 (0)