anne/lyx_mirror
1
0
Fork 0
mirror of https://git.lyx.org/repos/lyx.git synced 2024-12-22 13:18:28 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

Poor man's profiler: add support for cache hit/miss

Browse Source 
This is still very basic profiling, but it seems to get the work done.
This commit is contained in:
Jean-Marc Lasgouttes 2016-07-05 15:29:28 +02:00
parent f6bd79745e
commit be1c3f5fe3
1 changed files with 62 additions and 17 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

79
src/support/pmprof.h
View File

@ -8,7 +8,8 @@
* Full author contact details are available in file CREDITS. * Full author contact details are available in file CREDITS.
*/ */
/** How to use this trivial profiler: /**
* ==== HOW TO USE THIS TRIVIAL PROFILER:
* *
* * at the beginning of the interesting block, just add: * * at the beginning of the interesting block, just add:
* PROFILE_THIS_BLOCK(some_identifier) * PROFILE_THIS_BLOCK(some_identifier)
@ -17,7 +18,18 @@
* *
* * when the program ends, statistics will be sent to standard error, like: * * when the program ends, statistics will be sent to standard error, like:
* *
* ##### some_identifier: 6.48475usec, count=25405 * #pmprof# some_identifier: 6.51usec, count=7120, total=46.33msec
*
* * It is also possible to profile caching schemes. All it takes is an additional
* PROFILE_CACHE_MISS(some_identifier)
* in the place that takes care of cache misses. Then the output at the end will change to
*
* #pmprof# some_identifier: 6.51usec, count=7120, total=46.33msec
* hit: 96%, 4.36usec, count=6849, total=29.89msec
* miss: 3%, 60.65usec, count=271, total=16.43msec
*
*
* ==== ABOUT PROFILING SCOPE:
* *
* The code measured by the profiler corresponds to the lifetime of a * The code measured by the profiler corresponds to the lifetime of a
* local variable declared by the PROFILE_THIS_BLOCK macro. * local variable declared by the PROFILE_THIS_BLOCK macro.
@ -120,38 +132,66 @@ int gettimeofday(struct timeval * tv, struct timezone * /*tz*/)
#endif // _WIN32 #endif // _WIN32
namespace {
void dump(long long sec, long long usec, unsigned long long count) {
double const total = sec * 1000000 + usec;
std::cerr << std::fixed << std::setprecision(2)
<< total / count
<< "usec, count=" << count
<< ", total=" << total * 0.001 << "msec"
<< std::endl;
}
}
/* Helper class for gathering data. Instantiate this as a static /* Helper class for gathering data. Instantiate this as a static
* variable, so that its destructor will be executed when the program * variable, so that its destructor will be executed when the program
* ends. * ends.
*/ */
class PMProfStat { class PMProfStat {
public: public:
PMProfStat(char const * name) PMProfStat(char const * name) : name_(name), sec_(0), usec_(0), count_(0),
: name_(name), sec_(0), usec_(0), count_(0) {} miss_sec_(0), miss_usec_(0), miss_count_(0) {}
~PMProfStat() { ~PMProfStat() {
if (count_>0) { if (count_>0) {
double total = 0.001 * (sec_ * 1000000 + usec_); if (miss_count_ == 0) {
std::cerr << std::fixed << std::setprecision(2) std::cerr << "#pmprof# " << name_ << ": ";
<< "#pmprof# " << name_ << ": " dump(sec_, usec_, count_);
<< total / count_ }
<< "msec, count=" << count_ else {
<< ", total=" << total << "msec" std::cerr << "#pmprof# " << name_ << ": ";
<< std::endl; dump(sec_ + miss_sec_, usec_ + miss_usec_, count_ + miss_count_);
std::cerr << " hit: " << 100 * count_ / (count_ + miss_count_) << "%, ";
dump(sec_, usec_, count_);
std::cerr << " miss: " << 100 * miss_count_ / (count_ + miss_count_) << "%, ";
dump(miss_sec_, miss_usec_, miss_count_);
}
} }
} }
void add(const long long s, const long long u) { void add(const long long s, const long long u, const bool hit) {
sec_ += s; if (hit) {
usec_ += u; sec_ += s;
count_++; usec_ += u;
count_++;
} else {
miss_sec_ += s;
miss_usec_ += u;
miss_count_++;
}
} }
private: private:
char const * name_; char const * name_;
long long sec_, usec_; long long sec_, usec_;
unsigned long long count_; unsigned long long count_;
long long miss_sec_, miss_usec_;
unsigned long long miss_count_;
}; };
@ -162,7 +202,7 @@ private:
*/ */
class PMProfInstance { class PMProfInstance {
public: public:
PMProfInstance(PMProfStat * stat) : stat_(stat) PMProfInstance(PMProfStat * stat) : hit(true), stat_(stat)
{ {
gettimeofday(&before_, 0); gettimeofday(&before_, 0);
} }
@ -170,9 +210,11 @@ public:
~PMProfInstance() { ~PMProfInstance() {
gettimeofday(&after_, 0); gettimeofday(&after_, 0);
stat_->add(after_.tv_sec - before_.tv_sec, stat_->add(after_.tv_sec - before_.tv_sec,
after_.tv_usec - before_.tv_usec); after_.tv_usec - before_.tv_usec, hit);
} }
bool hit;
private: private:
timeval before_, after_; timeval before_, after_;
PMProfStat * stat_; PMProfStat * stat_;
@ -183,5 +225,8 @@ private:
static PMProfStat PMPS_##a(#a);\ static PMProfStat PMPS_##a(#a);\
PMProfInstance PMPI_##a(&PMPS_##a); PMProfInstance PMPI_##a(&PMPS_##a);
#define PROFILE_CACHE_MISS(a) \
PMPI_##a.hit = false;
#endif #endif