lix-project/lix
20
55
Fork 31
Code Issues 344 Code Review (Gerrit) Projects 3 Releases Wiki Activity

Add some basic profiling support to the evaluator

Browse source 
Setting the environment variable NIX_COUNT_CALLS to 1 enables some
basic profiling in the evaluator.  It will count calls to functions
and primops as well as evaluations of attributes.

For example, to see where evaluation of a NixOS configuration spends
its time:

$ NIX_SHOW_STATS=1 NIX_COUNT_CALLS=1 ./src/nix-instantiate/nix-instantiate '<nixos>' -A system --readonly-mode
...
calls to 39 primops:
    239532 head
    233962 tail
    191252 hasAttr
...
calls to 1595 functions:
    224157 `/nix/var/nix/profiles/per-user/root/channels/nixos/nixpkgs/pkgs/lib/lists.nix:17:19'
    221767 `/nix/var/nix/profiles/per-user/root/channels/nixos/nixpkgs/pkgs/lib/lists.nix:17:14'
    221767 `/nix/var/nix/profiles/per-user/root/channels/nixos/nixpkgs/pkgs/lib/lists.nix:17:10'
...
evaluations of 7088 attributes:
    167377 undefined position
    132459 `/nix/var/nix/profiles/per-user/root/channels/nixos/nixpkgs/pkgs/lib/attrsets.nix:119:41'
     47322 `/nix/var/nix/profiles/per-user/root/channels/nixos/nixpkgs/pkgs/lib/attrsets.nix:13:21'
...
This commit is contained in:
Eelco Dolstra 2012-08-12 23:29:28 -04:00
parent 325d1cfebf
commit e82767910c
5 changed files with 65 additions and 4 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

38
src/libexpr/eval.cc
View file

@ -144,6 +144,7 @@ EvalState::EvalState()
{
nrEnvs = nrValuesInEnvs = nrValues = nrListElems = 0;
nrAttrsets = nrOpUpdates = nrOpUpdateValuesCopied = 0;
countCalls = getEnv("NIX_COUNT_CALLS", "0") != "0";
#if HAVE_BOEHMGC
static bool gcInitialised = true;
@ -300,8 +301,10 @@ inline Value * EvalState::lookupVar(Env * env, const VarRef & var)
if (var.fromWith) {
while (1) {
Bindings::iterator j = env->values[0]->attrs->find(var.name);
if (j != env->values[0]->attrs->end())
if (j != env->values[0]->attrs->end()) {
if (countCalls && j->pos) attrSelects[*j->pos]++;
return j->value;
}
if (env->prevWith == 0)
throwEvalError("undefined variable `%1%'", var.name);
for (unsigned int l = env->prevWith; l; --l, env = env->up) ;
@ -619,8 +622,10 @@ void ExprSelect::eval(EvalState & state, Env & env, Value & v)
}
vAttrs = j->value;
pos = j->pos;
if (state.countCalls && pos) state.attrSelects[*pos]++;
}
state.forceValue(*vAttrs);
} catch (Error & e) {
@ -700,6 +705,7 @@ void EvalState::callFunction(Value & fun, Value & arg, Value & v)
vArgs[n--] = arg->primOpApp.right;
/* And call the primop. */
if (countCalls) primOpCalls[primOp->primOp->name]++;
try {
primOp->primOp->fun(*this, vArgs, v);
} catch (Error & e) {
@ -760,6 +766,8 @@ void EvalState::callFunction(Value & fun, Value & arg, Value & v)
throwTypeError("function at %1% called with unexpected argument", fun.lambda.fun->pos);
}
if (countCalls) functionCalls[fun.lambda.fun->pos]++;
try {
fun.lambda.fun->body->eval(*this, env2, v);
} catch (Error & e) {
@ -1216,6 +1224,34 @@ void EvalState::printStats()
printMsg(v, format(" number of thunks: %1%") % nrThunks);
printMsg(v, format(" number of thunks avoided: %1%") % nrAvoided);
printMsg(v, format(" number of attr lookups: %1%") % nrLookups);
if (countCalls) {
printMsg(v, format("calls to %1% primops:") % primOpCalls.size());
typedef std::multimap<unsigned int, Symbol> PrimOpCalls_;
std::multimap<unsigned int, Symbol> primOpCalls_;
foreach (PrimOpCalls::iterator, i, primOpCalls)
primOpCalls_.insert(std::pair<unsigned int, Symbol>(i->second, i->first));
foreach_reverse (PrimOpCalls_::reverse_iterator, i, primOpCalls_)
printMsg(v, format("%1$10d %2%") % i->first % i->second);
printMsg(v, format("calls to %1% functions:") % functionCalls.size());
typedef std::multimap<unsigned int, Pos> FunctionCalls_;
std::multimap<unsigned int, Pos> functionCalls_;
foreach (FunctionCalls::iterator, i, functionCalls)
functionCalls_.insert(std::pair<unsigned int, Pos>(i->second, i->first));
foreach_reverse (FunctionCalls_::reverse_iterator, i, functionCalls_)
printMsg(v, format("%1$10d %2%") % i->first % i->second);
printMsg(v, format("evaluations of %1% attributes:") % attrSelects.size());
typedef std::multimap<unsigned int, Pos> AttrSelects_;
std::multimap<unsigned int, Pos> attrSelects_;
foreach (AttrSelects::iterator, i, attrSelects)
attrSelects_.insert(std::pair<unsigned int, Pos>(i->second, i->first));
foreach_reverse (AttrSelects_::reverse_iterator, i, attrSelects_)
printMsg(v, format("%1$10d %2%") % i->first % i->second);
}
}

14
src/libexpr/eval.hh
View file

@ -245,8 +245,20 @@ private:
unsigned long nrOpUpdates;
unsigned long nrOpUpdateValuesCopied;
friend class RecursionCounter;
bool countCalls;
typedef std::map<Symbol, unsigned int> PrimOpCalls;
PrimOpCalls primOpCalls;
typedef std::map<Pos, unsigned int> FunctionCalls;
FunctionCalls functionCalls;
typedef std::map<Pos, unsigned int> AttrSelects;
AttrSelects attrSelects;
friend class ExprOpUpdate;
friend class ExprSelect;
friend void prim_getAttr(EvalState & state, Value * * args, Value & v);
};

9
src/libexpr/nixexpr.hh
View file

@ -27,6 +27,15 @@ struct Pos
Pos() : line(0), column(0) { };
Pos(const string & file, unsigned int line, unsigned int column)
: file(file), line(line), column(column) { };
bool operator < (const Pos & p2) const
{
int d = file.compare(p2.file);
if (d < 0) return true;
if (d > 0) return false;
if (line < p2.line) return true;
if (line > p2.line) return false;
return column < p2.column;
}
};
extern Pos noPos;

3
src/libexpr/primops.cc
View file

@ -713,7 +713,7 @@ static void prim_attrNames(EvalState & state, Value * * args, Value & v)
/* Dynamic version of the `.' operator. */
static void prim_getAttr(EvalState & state, Value * * args, Value & v)
void prim_getAttr(EvalState & state, Value * * args, Value & v)
{
string attr = state.forceStringNoCtx(*args[0]);
state.forceAttrs(*args[1]);
@ -722,6 +722,7 @@ static void prim_getAttr(EvalState & state, Value * * args, Value & v)
if (i == args[1]->attrs->end())
throw EvalError(format("attribute `%1%' missing") % attr);
// !!! add to stack trace?
if (state.countCalls && i->pos) state.attrSelects[*i->pos]++;
state.forceValue(*i->value);
v = *i->value;
}

3
src/libutil/util.hh
View file

@ -17,6 +17,9 @@ namespace nix {
#define foreach(it_type, it, collection) \
for (it_type it = (collection).begin(); it != (collection).end(); ++it)
#define foreach_reverse(it_type, it, collection) \
for (it_type it = (collection).rbegin(); it != (collection).rend(); ++it)
/* Return an environment variable. */
string getEnv(const string & key, const string & def = "");