1 //===-- StatsTracker.cpp --------------------------------------------------===//
2 //
3 //                     The KLEE Symbolic Virtual Machine
4 //
5 // This file is distributed under the University of Illinois Open Source
6 // License. See LICENSE.TXT for details.
7 //
8 //===----------------------------------------------------------------------===//
9 
10 #include "StatsTracker.h"
11 
12 #include "ExecutionState.h"
13 
14 #include "klee/Config/Version.h"
15 #include "klee/Module/InstructionInfoTable.h"
16 #include "klee/Module/KInstruction.h"
17 #include "klee/Module/KModule.h"
18 #include "klee/Solver/SolverStats.h"
19 #include "klee/Statistics/Statistics.h"
20 #include "klee/Support/ErrorHandling.h"
21 #include "klee/Support/ModuleUtil.h"
22 #include "klee/System/MemoryUsage.h"
23 
24 #include "CallPathManager.h"
25 #include "CoreStats.h"
26 #include "Executor.h"
27 #include "MemoryManager.h"
28 #include "UserSearcher.h"
29 
30 #include "llvm/ADT/SmallBitVector.h"
31 #include "llvm/IR/BasicBlock.h"
32 #if LLVM_VERSION_CODE < LLVM_VERSION(8, 0)
33 #include "llvm/IR/CallSite.h"
34 #endif
35 #include "llvm/IR/CFG.h"
36 #include "llvm/IR/Function.h"
37 #include "llvm/IR/InlineAsm.h"
38 #include "llvm/IR/Instructions.h"
39 #include "llvm/IR/IntrinsicInst.h"
40 #include "llvm/IR/Module.h"
41 #include "llvm/IR/Type.h"
42 #include "llvm/Support/CommandLine.h"
43 #include "llvm/Support/FileSystem.h"
44 #include "llvm/Support/Path.h"
45 #include "llvm/Support/Process.h"
46 
47 #include <fstream>
48 #include <unistd.h>
49 
50 using namespace klee;
51 using namespace llvm;
52 
53 ///
54 
55 namespace {
56 cl::OptionCategory
57     StatsCat("Statistics options",
58              "These options control the statistics generated by KLEE.");
59 
60 cl::opt<bool> TrackInstructionTime(
61     "track-instruction-time", cl::init(false),
62     cl::desc(
63         "Enable tracking of time for individual instructions (default=false)"),
64     cl::cat(StatsCat));
65 
66 cl::opt<bool>
67     OutputStats("output-stats", cl::init(true),
68                 cl::desc("Write running stats trace file (default=true)"),
69                 cl::cat(StatsCat));
70 
71 cl::opt<bool> OutputIStats("output-istats", cl::init(true),
72                            cl::desc("Write instruction level statistics in "
73                                     "callgrind format (default=true)"),
74                            cl::cat(StatsCat));
75 
76 cl::opt<std::string> StatsWriteInterval(
77     "stats-write-interval", cl::init("1s"),
78     cl::desc("Approximate time between stats writes (default=1s)"),
79     cl::cat(StatsCat));
80 
81 cl::opt<unsigned> StatsWriteAfterInstructions(
82     "stats-write-after-instructions", cl::init(0),
83     cl::desc(
84         "Write statistics after each n instructions, 0 to disable (default=0)"),
85     cl::cat(StatsCat));
86 
87   cl::opt<unsigned> CommitEvery(
88       "stats-commit-after", cl::init(0),
89       cl::desc("Commit the statistics every N writes. By default commit every "
90                "write with -stats-write-interval or every 1000 writes with "
91                "-stats-write-after-instructions. (default=0)"),
92       cl::cat(StatsCat));
93 
94 cl::opt<std::string> IStatsWriteInterval(
95     "istats-write-interval", cl::init("10s"),
96     cl::desc(
97         "Approximate number of seconds between istats writes (default=10s)"),
98     cl::cat(StatsCat));
99 
100 cl::opt<unsigned> IStatsWriteAfterInstructions(
101     "istats-write-after-instructions", cl::init(0),
102     cl::desc(
103         "Write istats after each n instructions, 0 to disable (default=0)"),
104     cl::cat(StatsCat));
105 
106 // XXX I really would like to have dynamic rate control for something like this.
107 cl::opt<std::string> UncoveredUpdateInterval(
108     "uncovered-update-interval", cl::init("30s"),
109     cl::desc("Update interval for uncovered instructions (default=30s)"),
110     cl::cat(StatsCat));
111 
112 cl::opt<bool> UseCallPaths("use-call-paths", cl::init(true),
113                            cl::desc("Enable calltree tracking for instruction "
114                                     "level statistics (default=true)"),
115                            cl::cat(StatsCat));
116 
117 } // namespace
118 
119 ///
120 
useStatistics()121 bool StatsTracker::useStatistics() {
122   return OutputStats || OutputIStats;
123 }
124 
useIStats()125 bool StatsTracker::useIStats() {
126   return OutputIStats;
127 }
128 
129 /// Check for special cases where we statically know an instruction is
130 /// uncoverable. Currently the case is an unreachable instruction
131 /// following a noreturn call; the instruction is really only there to
132 /// satisfy LLVM's termination requirement.
instructionIsCoverable(Instruction * i)133 static bool instructionIsCoverable(Instruction *i) {
134   if (i->getOpcode() == Instruction::Unreachable) {
135     BasicBlock *bb = i->getParent();
136     BasicBlock::iterator it(i);
137     if (it==bb->begin()) {
138       return true;
139     } else {
140       Instruction *prev = &*(--it);
141       if (isa<CallInst>(prev) || isa<InvokeInst>(prev)) {
142         Function *target = getDirectCallTarget(
143 #if LLVM_VERSION_CODE >= LLVM_VERSION(8, 0)
144             cast<CallBase>(*prev),
145 #else
146             CallSite(prev),
147 #endif
148             /*moduleIsFullyLinked=*/true);
149         if (target && target->doesNotReturn())
150           return false;
151       }
152     }
153   }
154 
155   return true;
156 }
157 
sqlite3ErrToStringAndFree(const std::string & prefix,char * sqlite3ErrMsg)158 std::string sqlite3ErrToStringAndFree(const std::string& prefix , char* sqlite3ErrMsg) {
159   std::ostringstream sstream;
160   sstream << prefix << sqlite3ErrMsg;
161   sqlite3_free(sqlite3ErrMsg);
162   return sstream.str();
163 }
164 
StatsTracker(Executor & _executor,std::string _objectFilename,bool _updateMinDistToUncovered)165 StatsTracker::StatsTracker(Executor &_executor, std::string _objectFilename,
166                            bool _updateMinDistToUncovered)
167   : executor(_executor),
168     objectFilename(_objectFilename),
169     startWallTime(time::getWallTime()),
170     numBranches(0),
171     fullBranches(0),
172     partialBranches(0),
173     updateMinDistToUncovered(_updateMinDistToUncovered) {
174 
175   const time::Span statsWriteInterval(StatsWriteInterval);
176   if (StatsWriteAfterInstructions > 0 && statsWriteInterval)
177     klee_error("Both options --stats-write-interval and "
178                "--stats-write-after-instructions cannot be enabled at the same "
179                "time.");
180 
181   const time::Span iStatsWriteInterval(IStatsWriteInterval);
182   if (IStatsWriteAfterInstructions > 0 && iStatsWriteInterval)
183     klee_error(
184         "Both options --istats-write-interval and "
185         "--istats-write-after-instructions cannot be enabled at the same "
186         "time.");
187 
188   KModule *km = executor.kmodule.get();
189   if(CommitEvery > 0) {
190       statsCommitEvery = CommitEvery;
191   } else {
192       statsCommitEvery = statsWriteInterval ? 1 : 1000;
193   }
194 
195   if (!sys::path::is_absolute(objectFilename)) {
196     SmallString<128> current(objectFilename);
197     if(sys::fs::make_absolute(current)) {
198       Twine current_twine(current.str()); // requires a twine for this
199       if (!sys::fs::exists(current_twine)) {
200         objectFilename = current.c_str();
201       }
202     }
203   }
204 
205   if (useStatistics() || userSearcherRequiresMD2U())
206     theStatisticManager->useIndexedStats(km->infos->getMaxID());
207 
208   for (auto &kfp : km->functions) {
209     KFunction *kf = kfp.get();
210     kf->trackCoverage = 1;
211 
212     for (unsigned i=0; i<kf->numInstructions; ++i) {
213       KInstruction *ki = kf->instructions[i];
214 
215       if (OutputIStats) {
216         unsigned id = ki->info->id;
217         theStatisticManager->setIndex(id);
218         if (kf->trackCoverage && instructionIsCoverable(ki->inst))
219           ++stats::uncoveredInstructions;
220       }
221 
222       if (kf->trackCoverage) {
223         if (BranchInst *bi = dyn_cast<BranchInst>(ki->inst))
224           if (!bi->isUnconditional())
225             numBranches++;
226       }
227     }
228   }
229 
230   if (OutputStats) {
231     sqlite3_config(SQLITE_CONFIG_SINGLETHREAD);
232     sqlite3_enable_shared_cache(0);
233 
234     // open database
235     auto db_filename = executor.interpreterHandler->getOutputFilename("run.stats");
236     if (sqlite3_open(db_filename.c_str(), &statsFile) != SQLITE_OK) {
237       std::ostringstream errorstream;
238       errorstream << "Can't open database: " << sqlite3_errmsg(statsFile);
239       sqlite3_close(statsFile);
240       klee_error("%s", errorstream.str().c_str());
241     }
242 
243     // prepare statements
244     if (sqlite3_prepare_v2(statsFile, "BEGIN TRANSACTION", -1, &transactionBeginStmt, nullptr) != SQLITE_OK) {
245       klee_error("Cannot create prepared statement: %s", sqlite3_errmsg(statsFile));
246     }
247 
248     if (sqlite3_prepare_v2(statsFile, "END TRANSACTION", -1, &transactionEndStmt, nullptr) != SQLITE_OK) {
249       klee_error("Cannot create prepared statement: %s", sqlite3_errmsg(statsFile));
250     }
251 
252     // set options
253     char *zErrMsg;
254     if (sqlite3_exec(statsFile, "PRAGMA synchronous = OFF", nullptr, nullptr, &zErrMsg) != SQLITE_OK) {
255       klee_error("%s", sqlite3ErrToStringAndFree("Can't set options for database: ", zErrMsg).c_str());
256     }
257 
258     // note: we use WAL here a) for speed and b) to prevent creation of new file descriptors (as with TRUNCATE)
259     if (sqlite3_exec(statsFile, "PRAGMA journal_mode = WAL", nullptr, nullptr, &zErrMsg) != SQLITE_OK) {
260       klee_error("%s", sqlite3ErrToStringAndFree("Can't set options for database: ", zErrMsg).c_str());
261     }
262 
263     // create table
264     writeStatsHeader();
265 
266     // begin transaction
267     auto rc = sqlite3_step(transactionBeginStmt);
268     if (rc != SQLITE_DONE) {
269       klee_warning("Can't begin transaction: %s", sqlite3_errmsg(statsFile));
270     }
271     sqlite3_reset(transactionBeginStmt);
272 
273     writeStatsLine();
274 
275     if (statsWriteInterval)
276       executor.timers.add(std::make_unique<Timer>(statsWriteInterval, [&]{
277         writeStatsLine();
278       }));
279   }
280 
281   // Add timer to calculate uncovered instructions if needed by the solver
282   if (updateMinDistToUncovered) {
283     computeReachableUncovered();
284     executor.timers.add(std::make_unique<Timer>(time::Span{UncoveredUpdateInterval}, [&]{
285       computeReachableUncovered();
286     }));
287   }
288 
289   if (OutputIStats) {
290     istatsFile = executor.interpreterHandler->openOutputFile("run.istats");
291     if (istatsFile) {
292       if (iStatsWriteInterval)
293         executor.timers.add(std::make_unique<Timer>(iStatsWriteInterval, [&]{
294           writeIStats();
295         }));
296     } else {
297       klee_error("Unable to open instruction level stats file (run.istats).");
298     }
299   }
300 }
301 
~StatsTracker()302 StatsTracker::~StatsTracker() {
303   if (statsFile) {
304     auto rc = sqlite3_step(transactionEndStmt);
305     if (rc != SQLITE_DONE) {
306       klee_warning("Can't commit transaction: %s", sqlite3_errmsg(statsFile));
307     }
308     sqlite3_reset(transactionEndStmt);
309     sqlite3_finalize(transactionBeginStmt);
310     sqlite3_finalize(transactionEndStmt);
311     sqlite3_finalize(insertStmt);
312     sqlite3_close(statsFile);
313   }
314 }
315 
done()316 void StatsTracker::done() {
317   if (statsFile)
318     writeStatsLine();
319 
320   if (OutputIStats) {
321     if (updateMinDistToUncovered)
322       computeReachableUncovered();
323     if (istatsFile)
324       writeIStats();
325   }
326 }
327 
stepInstruction(ExecutionState & es)328 void StatsTracker::stepInstruction(ExecutionState &es) {
329   if (OutputIStats) {
330     if (TrackInstructionTime) {
331       static time::Point lastNowTime(time::getWallTime());
332       static time::Span lastUserTime;
333 
334       if (!lastUserTime) {
335         lastUserTime = time::getUserTime();
336       } else {
337         const auto now = time::getWallTime();
338         const auto user = time::getUserTime();
339         const auto delta = user - lastUserTime;
340         const auto deltaNow = now - lastNowTime;
341         stats::instructionTime += delta.toMicroseconds();
342         stats::instructionRealTime += deltaNow.toMicroseconds();
343         lastUserTime = user;
344         lastNowTime = now;
345       }
346     }
347 
348     Instruction *inst = es.pc->inst;
349     const InstructionInfo &ii = *es.pc->info;
350     StackFrame &sf = es.stack.back();
351     theStatisticManager->setIndex(ii.id);
352     if (UseCallPaths)
353       theStatisticManager->setContext(&sf.callPathNode->statistics);
354 
355     if (es.instsSinceCovNew)
356       ++es.instsSinceCovNew;
357 
358     if (sf.kf->trackCoverage && instructionIsCoverable(inst)) {
359       if (!theStatisticManager->getIndexedValue(stats::coveredInstructions, ii.id)) {
360         // Checking for actual stoppoints avoids inconsistencies due
361         // to line number propogation.
362         //
363         // FIXME: This trick no longer works, we should fix this in the line
364         // number propogation.
365           es.coveredLines[&ii.file].insert(ii.line);
366 	es.coveredNew = true;
367         es.instsSinceCovNew = 1;
368 	++stats::coveredInstructions;
369 	stats::uncoveredInstructions += (uint64_t)-1;
370       }
371     }
372   }
373 
374   if (statsFile && StatsWriteAfterInstructions &&
375       stats::instructions % StatsWriteAfterInstructions.getValue() == 0)
376     writeStatsLine();
377 
378   if (istatsFile && IStatsWriteAfterInstructions &&
379       stats::instructions % IStatsWriteAfterInstructions.getValue() == 0)
380     writeIStats();
381 }
382 
383 ///
384 
385 /* Should be called _after_ the es->pushFrame() */
framePushed(ExecutionState & es,StackFrame * parentFrame)386 void StatsTracker::framePushed(ExecutionState &es, StackFrame *parentFrame) {
387   if (OutputIStats) {
388     StackFrame &sf = es.stack.back();
389 
390     if (UseCallPaths) {
391       CallPathNode *parent = parentFrame ? parentFrame->callPathNode : 0;
392       CallPathNode *cp = callPathManager.getCallPath(parent,
393                                                      sf.caller ? sf.caller->inst : 0,
394                                                      sf.kf->function);
395       sf.callPathNode = cp;
396       cp->count++;
397     }
398   }
399 
400   if (updateMinDistToUncovered) {
401     StackFrame &sf = es.stack.back();
402 
403     uint64_t minDistAtRA = 0;
404     if (parentFrame)
405       minDistAtRA = parentFrame->minDistToUncoveredOnReturn;
406 
407     sf.minDistToUncoveredOnReturn =
408         sf.caller ? computeMinDistToUncovered(sf.caller, minDistAtRA) : 0;
409   }
410 }
411 
412 /* Should be called _after_ the es->popFrame() */
framePopped(ExecutionState & es)413 void StatsTracker::framePopped(ExecutionState &es) {
414   // XXX remove me?
415 }
416 
markBranchVisited(ExecutionState * visitedTrue,ExecutionState * visitedFalse)417 void StatsTracker::markBranchVisited(ExecutionState *visitedTrue,
418                                      ExecutionState *visitedFalse) {
419   if (OutputIStats) {
420     unsigned id = theStatisticManager->getIndex();
421     uint64_t hasTrue = theStatisticManager->getIndexedValue(stats::trueBranches, id);
422     uint64_t hasFalse = theStatisticManager->getIndexedValue(stats::falseBranches, id);
423     if (visitedTrue && !hasTrue) {
424       visitedTrue->coveredNew = true;
425       visitedTrue->instsSinceCovNew = 1;
426       ++stats::trueBranches;
427       if (hasFalse) { ++fullBranches; --partialBranches; }
428       else ++partialBranches;
429       hasTrue = 1;
430     }
431     if (visitedFalse && !hasFalse) {
432       visitedFalse->coveredNew = true;
433       visitedFalse->instsSinceCovNew = 1;
434       ++stats::falseBranches;
435       if (hasTrue) { ++fullBranches; --partialBranches; }
436       else ++partialBranches;
437     }
438   }
439 }
440 
writeStatsHeader()441 void StatsTracker::writeStatsHeader() {
442   std::ostringstream create, insert;
443   create << "CREATE TABLE stats ("
444              << "Instructions INTEGER,"
445              << "FullBranches INTEGER,"
446              << "PartialBranches INTEGER,"
447              << "NumBranches INTEGER,"
448              << "UserTime REAL,"
449              << "NumStates INTEGER,"
450              << "MallocUsage INTEGER,"
451              << "NumQueries INTEGER,"
452              << "NumQueryConstructs INTEGER,"
453              << "WallTime REAL,"
454              << "CoveredInstructions INTEGER,"
455              << "UncoveredInstructions INTEGER,"
456              << "QueryTime INTEGER,"
457              << "SolverTime INTEGER,"
458              << "CexCacheTime INTEGER,"
459              << "ForkTime INTEGER,"
460              << "ResolveTime INTEGER,"
461              << "QueryCexCacheMisses INTEGER,"
462              << "QueryCexCacheHits INTEGER,"
463              << "ArrayHashTime INTEGER"
464          << ')';
465   char *zErrMsg = nullptr;
466   if(sqlite3_exec(statsFile, create.str().c_str(), nullptr, nullptr, &zErrMsg)) {
467     klee_error("%s", sqlite3ErrToStringAndFree("ERROR creating table: ", zErrMsg).c_str());
468   }
469   /* Sometimes KLEE runs out of file descriptors and hence we try to a) keep important fds open and b) prevent the
470    * creation of temporary files. SQLite3 uses temporary files for statement journals, which help rollbacks when
471    * constraints are violated. We have no constraints in our table so there shouldn't be a constraint violation.
472    * `OR FAIL` will not write to temp files and therefore not rollback but simply fail. As said before this should not
473    * happen, but if it does this statement will fail with SQLITE_CONSTRAINT error. If this happens you should either
474    * remove the constraints or consider using `IGNORE` mode.
475    */
476   insert << "INSERT OR FAIL INTO stats ("
477              << "Instructions,"
478              << "FullBranches,"
479              << "PartialBranches,"
480              << "NumBranches,"
481              << "UserTime,"
482              << "NumStates,"
483              << "MallocUsage,"
484              << "NumQueries,"
485              << "NumQueryConstructs,"
486              << "WallTime,"
487              << "CoveredInstructions,"
488              << "UncoveredInstructions,"
489              << "QueryTime,"
490              << "SolverTime,"
491              << "CexCacheTime,"
492              << "ForkTime,"
493              << "ResolveTime,"
494              << "QueryCexCacheMisses,"
495              << "QueryCexCacheHits,"
496              << "ArrayHashTime"
497          << ") VALUES ("
498              << "?,"
499              << "?,"
500              << "?,"
501              << "?,"
502              << "?,"
503              << "?,"
504              << "?,"
505              << "?,"
506              << "?,"
507              << "?,"
508              << "?,"
509              << "?,"
510              << "?,"
511              << "?,"
512              << "?,"
513              << "?,"
514              << "?,"
515              << "?,"
516              << "?,"
517              << "? "
518          << ')';
519 
520   if(sqlite3_prepare_v2(statsFile, insert.str().c_str(), -1, &insertStmt, nullptr) != SQLITE_OK) {
521     klee_error("Cannot create prepared statement: %s", sqlite3_errmsg(statsFile));
522   }
523 }
524 
elapsed()525 time::Span StatsTracker::elapsed() {
526   return time::getWallTime() - startWallTime;
527 }
528 
writeStatsLine()529 void StatsTracker::writeStatsLine() {
530   sqlite3_bind_int64(insertStmt, 1, stats::instructions);
531   sqlite3_bind_int64(insertStmt, 2, fullBranches);
532   sqlite3_bind_int64(insertStmt, 3, partialBranches);
533   sqlite3_bind_int64(insertStmt, 4, numBranches);
534   sqlite3_bind_int64(insertStmt, 5, time::getUserTime().toMicroseconds());
535   sqlite3_bind_int64(insertStmt, 6, executor.states.size());
536   sqlite3_bind_int64(insertStmt, 7, util::GetTotalMallocUsage() + executor.memory->getUsedDeterministicSize());
537   sqlite3_bind_int64(insertStmt, 8, stats::queries);
538   sqlite3_bind_int64(insertStmt, 9, stats::queryConstructs);
539   sqlite3_bind_int64(insertStmt, 10, elapsed().toMicroseconds());
540   sqlite3_bind_int64(insertStmt, 11, stats::coveredInstructions);
541   sqlite3_bind_int64(insertStmt, 12, stats::uncoveredInstructions);
542   sqlite3_bind_int64(insertStmt, 13, stats::queryTime);
543   sqlite3_bind_int64(insertStmt, 14, stats::solverTime);
544   sqlite3_bind_int64(insertStmt, 15, stats::cexCacheTime);
545   sqlite3_bind_int64(insertStmt, 16, stats::forkTime);
546   sqlite3_bind_int64(insertStmt, 17, stats::resolveTime);
547   sqlite3_bind_int64(insertStmt, 18, stats::queryCexCacheMisses);
548   sqlite3_bind_int64(insertStmt, 19, stats::queryCexCacheHits);
549 #ifdef KLEE_ARRAY_DEBUG
550   sqlite3_bind_int64(insertStmt, 20, stats::arrayHashTime);
551 #else
552   sqlite3_bind_int64(insertStmt, 20, -1LL);
553 #endif
554   int errCode = sqlite3_step(insertStmt);
555   if(errCode != SQLITE_DONE) klee_error("Error writing stats data: %s", sqlite3_errmsg(statsFile));
556   sqlite3_reset(insertStmt);
557 
558   statsWriteCount++;
559   if(statsWriteCount == statsCommitEvery) {
560     errCode = sqlite3_step(transactionEndStmt);
561     if (errCode != SQLITE_DONE) klee_warning("Transaction commit error: %s", sqlite3_errmsg(statsFile));
562     sqlite3_reset(transactionEndStmt);
563     errCode = sqlite3_step(transactionBeginStmt);
564     if (errCode != SQLITE_DONE) klee_warning("Transaction begin error: %s", sqlite3_errmsg(statsFile));
565     sqlite3_reset(transactionBeginStmt);
566 
567     statsWriteCount = 0;
568   }
569 }
570 
updateStateStatistics(uint64_t addend)571 void StatsTracker::updateStateStatistics(uint64_t addend) {
572   for (std::set<ExecutionState*>::iterator it = executor.states.begin(),
573          ie = executor.states.end(); it != ie; ++it) {
574     ExecutionState &state = **it;
575     const InstructionInfo &ii = *state.pc->info;
576     theStatisticManager->incrementIndexedValue(stats::states, ii.id, addend);
577     if (UseCallPaths)
578       state.stack.back().callPathNode->statistics.incrementValue(stats::states, addend);
579   }
580 }
581 
writeIStats()582 void StatsTracker::writeIStats() {
583   const auto m = executor.kmodule->module.get();
584   llvm::raw_fd_ostream &of = *istatsFile;
585 
586   // We assume that we didn't move the file pointer
587   unsigned istatsSize = of.tell();
588 
589   of.seek(0);
590 
591   of << "version: 1\n";
592   of << "creator: klee\n";
593   of << "pid: " << getpid() << "\n";
594   of << "cmd: " << m->getModuleIdentifier() << "\n\n";
595   of << "\n";
596 
597   StatisticManager &sm = *theStatisticManager;
598   unsigned nStats = sm.getNumStatistics();
599   llvm::SmallBitVector istatsMask(nStats);
600 
601   istatsMask.set(sm.getStatisticID("Queries"));
602   istatsMask.set(sm.getStatisticID("QueriesValid"));
603   istatsMask.set(sm.getStatisticID("QueriesInvalid"));
604   istatsMask.set(sm.getStatisticID("QueryTime"));
605   istatsMask.set(sm.getStatisticID("ResolveTime"));
606   istatsMask.set(sm.getStatisticID("Instructions"));
607   istatsMask.set(sm.getStatisticID("InstructionTimes"));
608   istatsMask.set(sm.getStatisticID("InstructionRealTimes"));
609   istatsMask.set(sm.getStatisticID("Forks"));
610   istatsMask.set(sm.getStatisticID("CoveredInstructions"));
611   istatsMask.set(sm.getStatisticID("UncoveredInstructions"));
612   istatsMask.set(sm.getStatisticID("States"));
613   istatsMask.set(sm.getStatisticID("MinDistToUncovered"));
614 
615   of << "positions: instr line\n";
616 
617   for (unsigned i=0; i<nStats; i++) {
618     if (istatsMask.test(i)) {
619       Statistic &s = sm.getStatistic(i);
620       of << "event: " << s.getShortName() << " : "
621          << s.getName() << "\n";
622     }
623   }
624 
625   of << "events: ";
626   for (unsigned i=0; i<nStats; i++) {
627     if (istatsMask.test(i))
628       of << sm.getStatistic(i).getShortName() << " ";
629   }
630   of << "\n";
631 
632   // set state counts, decremented after we process so that we don't
633   // have to zero all records each time.
634   if (istatsMask.test(stats::states.getID()))
635     updateStateStatistics(1);
636 
637   std::string sourceFile = "";
638 
639   CallSiteSummaryTable callSiteStats;
640   if (UseCallPaths)
641     callPathManager.getSummaryStatistics(callSiteStats);
642 
643   of << "ob=" << llvm::sys::path::filename(objectFilename).str() << "\n";
644 
645   for (Module::iterator fnIt = m->begin(), fn_ie = m->end();
646        fnIt != fn_ie; ++fnIt) {
647     if (!fnIt->isDeclaration()) {
648       // Always try to write the filename before the function name, as otherwise
649       // KCachegrind can create two entries for the function, one with an
650       // unnamed file and one without.
651       Function *fn = &*fnIt;
652       const FunctionInfo &ii = executor.kmodule->infos->getFunctionInfo(*fn);
653       if (ii.file != sourceFile) {
654         of << "fl=" << ii.file << "\n";
655         sourceFile = ii.file;
656       }
657 
658       of << "fn=" << fnIt->getName().str() << "\n";
659       for (Function::iterator bbIt = fnIt->begin(), bb_ie = fnIt->end();
660            bbIt != bb_ie; ++bbIt) {
661         for (BasicBlock::iterator it = bbIt->begin(), ie = bbIt->end();
662              it != ie; ++it) {
663           Instruction *instr = &*it;
664           const InstructionInfo &ii = executor.kmodule->infos->getInfo(*instr);
665           unsigned index = ii.id;
666           if (ii.file!=sourceFile) {
667             of << "fl=" << ii.file << "\n";
668             sourceFile = ii.file;
669           }
670           of << ii.assemblyLine << " ";
671           of << ii.line << " ";
672           for (unsigned i=0; i<nStats; i++)
673             if (istatsMask.test(i))
674               of << sm.getIndexedValue(sm.getStatistic(i), index) << " ";
675           of << "\n";
676 
677           if (UseCallPaths &&
678               (isa<CallInst>(instr) || isa<InvokeInst>(instr))) {
679             CallSiteSummaryTable::iterator it = callSiteStats.find(instr);
680             if (it!=callSiteStats.end()) {
681               for (auto fit = it->second.begin(), fie = it->second.end();
682                    fit != fie; ++fit) {
683                 const Function *f = fit->first;
684                 CallSiteInfo &csi = fit->second;
685                 const FunctionInfo &fii =
686                     executor.kmodule->infos->getFunctionInfo(*f);
687 
688                 if (fii.file!="" && fii.file!=sourceFile)
689                   of << "cfl=" << fii.file << "\n";
690                 of << "cfn=" << f->getName().str() << "\n";
691                 of << "calls=" << csi.count << " ";
692                 of << fii.assemblyLine << " ";
693                 of << fii.line << "\n";
694 
695                 of << ii.assemblyLine << " ";
696                 of << ii.line << " ";
697                 for (unsigned i=0; i<nStats; i++) {
698                   if (istatsMask.test(i)) {
699                     Statistic &s = sm.getStatistic(i);
700                     uint64_t value;
701 
702                     // Hack, ignore things that don't make sense on
703                     // call paths.
704                     if (&s == &stats::uncoveredInstructions) {
705                       value = 0;
706                     } else {
707                       value = csi.statistics.getValue(s);
708                     }
709 
710                     of << value << " ";
711                   }
712                 }
713                 of << "\n";
714               }
715             }
716           }
717         }
718       }
719     }
720   }
721 
722   if (istatsMask.test(stats::states.getID()))
723     updateStateStatistics((uint64_t)-1);
724 
725   // Clear then end of the file if necessary (no truncate op?).
726   unsigned pos = of.tell();
727   for (unsigned i=pos; i<istatsSize; ++i)
728     of << '\n';
729 
730   of.flush();
731 }
732 
733 ///
734 
735 typedef std::map<Instruction*, std::vector<Function*> > calltargets_ty;
736 
737 static calltargets_ty callTargets;
738 static std::map<Function*, std::vector<Instruction*> > functionCallers;
739 static std::map<Function*, unsigned> functionShortestPath;
740 
getSuccs(Instruction * i)741 static std::vector<Instruction*> getSuccs(Instruction *i) {
742   BasicBlock *bb = i->getParent();
743   std::vector<Instruction*> res;
744 
745   if (i==bb->getTerminator()) {
746     for (succ_iterator it = succ_begin(bb), ie = succ_end(bb); it != ie; ++it)
747       res.push_back(&*(it->begin()));
748   } else {
749     res.push_back(&*(++(i->getIterator())));
750   }
751 
752   return res;
753 }
754 
computeMinDistToUncovered(const KInstruction * ki,uint64_t minDistAtRA)755 uint64_t klee::computeMinDistToUncovered(const KInstruction *ki,
756                                          uint64_t minDistAtRA) {
757   StatisticManager &sm = *theStatisticManager;
758   if (minDistAtRA==0) { // unreachable on return, best is local
759     return sm.getIndexedValue(stats::minDistToUncovered,
760                               ki->info->id);
761   } else {
762     uint64_t minDistLocal = sm.getIndexedValue(stats::minDistToUncovered,
763                                                ki->info->id);
764     uint64_t distToReturn = sm.getIndexedValue(stats::minDistToReturn,
765                                                ki->info->id);
766 
767     if (distToReturn==0) { // return unreachable, best is local
768       return minDistLocal;
769     } else if (!minDistLocal) { // no local reachable
770       return distToReturn + minDistAtRA;
771     } else {
772       return std::min(minDistLocal, distToReturn + minDistAtRA);
773     }
774   }
775 }
776 
computeReachableUncovered()777 void StatsTracker::computeReachableUncovered() {
778   KModule *km = executor.kmodule.get();
779   const auto m = km->module.get();
780   static bool init = true;
781   const InstructionInfoTable &infos = *km->infos;
782   StatisticManager &sm = *theStatisticManager;
783 
784   if (init) {
785     init = false;
786 
787     // Compute call targets. It would be nice to use alias information
788     // instead of assuming all indirect calls hit all escaping
789     // functions, eh?
790     for (Module::iterator fnIt = m->begin(), fn_ie = m->end();
791          fnIt != fn_ie; ++fnIt) {
792       for (Function::iterator bbIt = fnIt->begin(), bb_ie = fnIt->end();
793            bbIt != bb_ie; ++bbIt) {
794         for (BasicBlock::iterator it = bbIt->begin(), ie = bbIt->end();
795              it != ie; ++it) {
796           Instruction *inst = &*it;
797           if (isa<CallInst>(inst) || isa<InvokeInst>(inst)) {
798 #if LLVM_VERSION_CODE >= LLVM_VERSION(8, 0)
799             const CallBase &cs = cast<CallBase>(*inst);
800             if (isa<InlineAsm>(cs.getCalledOperand())) {
801 #else
802             const CallSite cs(inst);
803             if (isa<InlineAsm>(cs.getCalledValue())) {
804 #endif
805               // We can never call through here so assume no targets
806               // (which should be correct anyhow).
807               callTargets.insert(std::make_pair(inst,
808                                                 std::vector<Function*>()));
809             } else if (Function *target = getDirectCallTarget(
810                            cs, /*moduleIsFullyLinked=*/true)) {
811               callTargets[inst].push_back(target);
812             } else {
813               callTargets[inst] =
814                 std::vector<Function*>(km->escapingFunctions.begin(),
815                                        km->escapingFunctions.end());
816             }
817           }
818         }
819       }
820     }
821 
822     // Compute function callers as reflexion of callTargets.
823     for (calltargets_ty::iterator it = callTargets.begin(),
824            ie = callTargets.end(); it != ie; ++it)
825       for (std::vector<Function*>::iterator fit = it->second.begin(),
826              fie = it->second.end(); fit != fie; ++fit)
827         functionCallers[*fit].push_back(it->first);
828 
829     // Initialize minDistToReturn to shortest paths through
830     // functions. 0 is unreachable.
831     std::vector<Instruction *> instructions;
832     for (Module::iterator fnIt = m->begin(), fn_ie = m->end();
833          fnIt != fn_ie; ++fnIt) {
834       Function *fn = &*fnIt;
835       if (fnIt->isDeclaration()) {
836         if (fnIt->doesNotReturn()) {
837           functionShortestPath[fn] = 0;
838         } else {
839           functionShortestPath[fn] = 1; // whatever
840         }
841       } else {
842         functionShortestPath[fn] = 0;
843       }
844 
845       // Not sure if I should bother to preorder here. XXX I should.
846       for (Function::iterator bbIt = fnIt->begin(), bb_ie = fnIt->end();
847            bbIt != bb_ie; ++bbIt) {
848         for (BasicBlock::iterator it = bbIt->begin(), ie = bbIt->end();
849              it != ie; ++it) {
850           Instruction *inst = &*it;
851           instructions.push_back(inst);
852           unsigned id = infos.getInfo(*inst).id;
853           sm.setIndexedValue(stats::minDistToReturn,
854                              id,
855                              isa<ReturnInst>(inst)
856                              );
857         }
858       }
859     }
860 
861     std::reverse(instructions.begin(), instructions.end());
862 
863     // I'm so lazy it's not even worklisted.
864     bool changed;
865     do {
866       changed = false;
867       for (auto it = instructions.begin(), ie = instructions.end(); it != ie;
868            ++it) {
869         Instruction *inst = *it;
870         unsigned bestThrough = 0;
871 
872         if (isa<CallInst>(inst) || isa<InvokeInst>(inst)) {
873           std::vector<Function*> &targets = callTargets[inst];
874           for (std::vector<Function*>::iterator fnIt = targets.begin(),
875                  ie = targets.end(); fnIt != ie; ++fnIt) {
876             uint64_t dist = functionShortestPath[*fnIt];
877             if (dist) {
878               dist = 1+dist; // count instruction itself
879               if (bestThrough==0 || dist<bestThrough)
880                 bestThrough = dist;
881             }
882           }
883         } else {
884           bestThrough = 1;
885         }
886 
887         if (bestThrough) {
888           unsigned id = infos.getInfo(*(*it)).id;
889           uint64_t best, cur = best = sm.getIndexedValue(stats::minDistToReturn, id);
890           std::vector<Instruction*> succs = getSuccs(*it);
891           for (std::vector<Instruction*>::iterator it2 = succs.begin(),
892                  ie = succs.end(); it2 != ie; ++it2) {
893             uint64_t dist = sm.getIndexedValue(stats::minDistToReturn,
894                                                infos.getInfo(*(*it2)).id);
895             if (dist) {
896               uint64_t val = bestThrough + dist;
897               if (best==0 || val<best)
898                 best = val;
899             }
900           }
901           // there's a corner case here when a function only includes a single
902           // instruction (a ret). in that case, we MUST update
903           // functionShortestPath, or it will remain 0 (erroneously indicating
904           // that no return instructions are reachable)
905           Function *f = inst->getParent()->getParent();
906           if (best != cur || (inst == &*(f->begin()->begin())
907                   && functionShortestPath[f] != best)) {
908             sm.setIndexedValue(stats::minDistToReturn, id, best);
909             changed = true;
910 
911             // Update shortest path if this is the entry point.
912             if (inst == &*(f->begin()->begin()))
913               functionShortestPath[f] = best;
914           }
915         }
916       }
917     } while (changed);
918   }
919 
920   // compute minDistToUncovered, 0 is unreachable
921   std::vector<Instruction *> instructions;
922   for (Module::iterator fnIt = m->begin(), fn_ie = m->end();
923        fnIt != fn_ie; ++fnIt) {
924     // Not sure if I should bother to preorder here.
925     for (Function::iterator bbIt = fnIt->begin(), bb_ie = fnIt->end();
926          bbIt != bb_ie; ++bbIt) {
927       for (BasicBlock::iterator it = bbIt->begin(), ie = bbIt->end();
928            it != ie; ++it) {
929         Instruction *inst = &*it;
930         unsigned id = infos.getInfo(*inst).id;
931         instructions.push_back(inst);
932         sm.setIndexedValue(stats::minDistToUncovered,
933                            id,
934                            sm.getIndexedValue(stats::uncoveredInstructions, id));
935       }
936     }
937   }
938 
939   std::reverse(instructions.begin(), instructions.end());
940 
941   // I'm so lazy it's not even worklisted.
942   bool changed;
943   do {
944     changed = false;
945     for (std::vector<Instruction*>::iterator it = instructions.begin(),
946            ie = instructions.end(); it != ie; ++it) {
947       Instruction *inst = *it;
948       uint64_t best, cur = best = sm.getIndexedValue(stats::minDistToUncovered,
949                                                      infos.getInfo(*inst).id);
950       unsigned bestThrough = 0;
951 
952       if (isa<CallInst>(inst) || isa<InvokeInst>(inst)) {
953         std::vector<Function*> &targets = callTargets[inst];
954         for (std::vector<Function*>::iterator fnIt = targets.begin(),
955                ie = targets.end(); fnIt != ie; ++fnIt) {
956           uint64_t dist = functionShortestPath[*fnIt];
957           if (dist) {
958             dist = 1+dist; // count instruction itself
959             if (bestThrough==0 || dist<bestThrough)
960               bestThrough = dist;
961           }
962 
963           if (!(*fnIt)->isDeclaration()) {
964             uint64_t calleeDist = sm.getIndexedValue(
965                 stats::minDistToUncovered, infos.getFunctionInfo(*(*fnIt)).id);
966             if (calleeDist) {
967               calleeDist = 1+calleeDist; // count instruction itself
968               if (best==0 || calleeDist<best)
969                 best = calleeDist;
970             }
971           }
972         }
973       } else {
974         bestThrough = 1;
975       }
976 
977       if (bestThrough) {
978         std::vector<Instruction*> succs = getSuccs(inst);
979         for (std::vector<Instruction*>::iterator it2 = succs.begin(),
980                ie = succs.end(); it2 != ie; ++it2) {
981           uint64_t dist = sm.getIndexedValue(stats::minDistToUncovered,
982                                              infos.getInfo(*(*it2)).id);
983           if (dist) {
984             uint64_t val = bestThrough + dist;
985             if (best==0 || val<best)
986               best = val;
987           }
988         }
989       }
990 
991       if (best != cur) {
992         sm.setIndexedValue(stats::minDistToUncovered, infos.getInfo(*inst).id,
993                            best);
994         changed = true;
995       }
996     }
997   } while (changed);
998 
999   for (std::set<ExecutionState*>::iterator it = executor.states.begin(),
1000          ie = executor.states.end(); it != ie; ++it) {
1001     ExecutionState *es = *it;
1002     uint64_t currentFrameMinDist = 0;
1003     for (ExecutionState::stack_ty::iterator sfIt = es->stack.begin(),
1004            sf_ie = es->stack.end(); sfIt != sf_ie; ++sfIt) {
1005       ExecutionState::stack_ty::iterator next = sfIt + 1;
1006       KInstIterator kii;
1007 
1008       if (next==es->stack.end()) {
1009         kii = es->pc;
1010       } else {
1011         kii = next->caller;
1012         ++kii;
1013       }
1014 
1015       sfIt->minDistToUncoveredOnReturn = currentFrameMinDist;
1016 
1017       currentFrameMinDist = computeMinDistToUncovered(kii, currentFrameMinDist);
1018     }
1019   }
1020 }
1021