Re: Profiler class, suggestions and comments welcome
Here is the third version of my profiler, added at the bottom of my
post.
GoogleGroups will eventually cut it and add a "read more" link, hence
I'm posting my questions here.
- Shall I start adding "throw()" to all functions - and ensure that
none of them actually throws by wrapping the code into try / catch
blocks?
- Does it make any difference to use clock_t against std::clock_t (and
the alike, using C functions incorporated into the std namespace)?
- Why do I get strange warnings about uninitialized variables about
the instantiation of the STL containers? Is my code faulty or it is
due to some gcc oddity?
One warning for all:
-------
C:/Programmi/CodeBlocks/MinGW/bin/../lib/gcc/mingw32/3.4.5/../../../../
include/c++/3.4.5/bits/stl_vector.h: In member function
`std::vector<_Tp, _Alloc>& std::vector<_Tp, _Alloc>::operator=(const
std::vector<_Tp, _Alloc>&) [with _Tp = profiler_utils::TimingRec,
_Alloc = std::allocator<profiler_utils::TimingRec>]':
C:/Programmi/CodeBlocks/MinGW/bin/../lib/gcc/mingw32/3.4.5/../../../../
include/c++/3.4.5/bits/stl_vector.h:715: warning: '__result' might be
used uninitialized in this function
-------
As for the 2nd version, the only real issue I was able to find by
myself was about a potential division by zero, now made harmless -
although, sticking to the code I posted, wasn't really likely to
happen.
About the new version, the new features are quite straightforward to
understand, here is the code, I'll be happy to read your comments,
fixes and, once more, to receive your slaps for my bad habits.
No disclaimer. If I left something in, it means I meant to leave it in
or, otherwise, I missed to get the point, hence feel free to dissect.
Thank you very much for your attention and for your help,
best regards,
Francesco
-------
// **********************************
// profiler utility, 3rd version
// all files thrown together
// **********************************
// **********************************
// profiler_utils.h
// (double-incl checks snipped)
// **********************************
#include <iostream>
#include <string>
#include <vector>
#include <ctime>
namespace profiler_utils {
class Profiler {
public:
Profiler(const std::string& sid)
: id(sid),
start_time(std::clock()) {} // start_time must be initialized
last
~Profiler();
private:
Profiler(const Profiler&);
const Profiler& operator=(const Profiler&);
std::string id;
std::clock_t start_time; // start_time must be declared last
};
struct TimingRec {
std::string id;
double avg_time;
double total_time;
int calls_count;
TimingRec() : avg_time(0), total_time(0), calls_count(0) {}
};
inline std::ostream& operator<<(std::ostream& os, const TimingRec& r)
{
os << " Id: " << r.id << "\n";
os << " Avg time: " << r.avg_time << " msecs\n";
os << " Total time: " << r.total_time << " msecs\n";
os << "Calls count: " << r.calls_count << "\n";
return os;
}
void report(std::ostream&);
std::string report();
void reset();
TimingRec get_record(const std::string&);
std::vector<TimingRec> most_called();
std::vector<TimingRec> most_expensive();
std::vector<TimingRec> most_timespent();
} // end profiler namespace
// **********************************
// profiler.cpp
// **********************************
//#include "profiler_utils.h"
#include <map>
#include <sstream>
namespace {
struct timing_record {
std::clock_t total_time;
int calls_count;
timing_record(): total_time(0), calls_count(0) {}
};
inline profiler_utils::TimingRec makeTimingRec(const std::string& s,
const timing_record& r) {
profiler_utils::TimingRec res;
res.id = s;
if (r.calls_count) {
res.avg_time = 1000.0 * r.total_time / CLOCKS_PER_SEC /
r.calls_count;
} else {
res.id += " [bad record]";
}
res.total_time = 1000.0 * r.total_time / CLOCKS_PER_SEC;
res.calls_count = r.calls_count;
return res;
}
typedef std::map<std::string, timing_record> timing_map_type;
typedef timing_map_type::const_iterator t_map_iter;
// main data depot
timing_map_type t_map;
// stats indexes
std::map<double, std::vector<std::string> > avg_t_map;
std::map<std::clock_t, std::vector<std::string> > total_t_map;
std::map<int, std::vector<std::string> > calls_map;
bool must_rebuild;
void rebuild_indexes() {
if (must_rebuild) {
avg_t_map.clear();
total_t_map.clear();
calls_map.clear();
for (t_map_iter it = t_map.begin(), end = t_map.end(); it != end; +
+it) {
const std::string& id = it->first;
const timing_record& tr = it->second;
if (tr.calls_count) {
avg_t_map[double(tr.total_time) / tr.calls_count].push_back
(id);
}
total_t_map[tr.total_time].push_back(id);
calls_map[tr.calls_count].push_back(id);
}
must_rebuild = false;
}
}
void fill_vector(const std::vector<std::string>& ids,
std::vector<profiler_utils::TimingRec>* recs) {
for (size_t i = 0, end = ids.size(); i < end; ++i) {
t_map_iter it = t_map.find(ids[i]);
if (it != t_map.end()) {
recs->push_back(makeTimingRec(it->first, it->second));
}
}
}
} // end anonymous namespace
profiler_utils::Profiler::~Profiler() {
std::clock_t ct = std::clock() - start_time;
timing_record& tr = t_map[id];
tr.total_time += ct;
++tr.calls_count;
must_rebuild = true;
}
void profiler_utils::report(std::ostream& stream) {
stream << "\n---[ profiler report ]---\n\n";
if (t_map.size()) {
for (t_map_iter it = t_map.begin(), end = t_map.end(); it != end; +
+it) {
stream << makeTimingRec(it->first, it->second) << "\n";
}
} else {
stream << "Nothing to report.\n\n";
}
stream << "---[ end report ]--------\n";
}
std::string profiler_utils::report() {
std::ostringstream res;
report(res);
return res.str();
}
void profiler_utils::reset() {
t_map.clear();
must_rebuild = true;
}
profiler_utils::TimingRec profiler_utils::get_record(const
std::string& id) {
t_map_iter it = t_map.find(id);
if (it != t_map.end()) {
return makeTimingRec(it->first, it->second);
} else {
return makeTimingRec("", timing_record());
}
}
std::vector<profiler_utils::TimingRec> profiler_utils::most_called() {
rebuild_indexes();
std::vector<TimingRec> res;
if (calls_map.size()) {
fill_vector(calls_map.rbegin()->second, &res);
}
return res;
}
std::vector<profiler_utils::TimingRec> profiler_utils::most_expensive
() {
rebuild_indexes();
std::vector<TimingRec> res;
if (avg_t_map.size()) {
fill_vector(avg_t_map.rbegin()->second, &res);
}
return res;
}
std::vector<profiler_utils::TimingRec> profiler_utils::most_timespent
() {
rebuild_indexes();
std::vector<TimingRec> res;
if (total_t_map.size()) {
fill_vector(total_t_map.rbegin()->second, &res);
}
return res;
}
// **********************************
// main.cpp - test case
// **********************************
//#include "profiler_utils.h"
using namespace std;
using namespace profiler_utils;
const string sMC = "Most called function";
const string sME = "Most expensive function";
const string sMT = "Most timespent function";
void Test();
void MostCalled();
void MostExpensive();
void MostTimeSpent();
int main()
{
for (size_t i = 0; i < 50; ++i) {
MostCalled();
}
MostExpensive();
for (size_t i = 0; i < 20; ++i) {
MostTimeSpent();
}
const string sep = string(50, '*') + "\n";
cout << sep << " Test results:\n" << sep;
Test();
report(cout);
reset();
cout << endl;
cout << sep << " Test results after resetting:\n" << sep;
Test();
cout << report() << endl;
return 0;
}
void Test() {
cout << "\nGetting most_called()..." << endl;
vector<TimingRec> res = most_called();
if (res.size()) {
if (res[0].id == sMC) {
cout << res[0];
} else {
cout << "Check failed!" << endl;
}
} else {
cout << "Nothing got!" << endl;
}
cout << endl;
cout << "Getting most_expensive()..." << endl;
res = most_expensive();
if (res.size()) {
if (res[0].id == sME) {
cout << res[0];
} else {
cout << "Check failed!" << endl;
}
} else {
cout << "Nothing got!" << endl;
}
cout << endl;
cout << "Getting most_timespent()..." << endl;
res = most_timespent();
if (res.size()) {
if (res[0].id == sMT) {
cout << res[0];
} else {
cout << "Check failed!" << endl;
}
} else {
cout << "Nothing got!" << endl;
}
cout << endl;
cout << "Getting get_record(\"" << sMC << "\")..." << endl;
cout << get_record(sMC) << endl;
cout << "Getting get_record(\"" << sME << "\")..." << endl;
cout << get_record(sME) << endl;
cout << "Getting get_record(\"" << sMT << "\")..." << endl;
cout << get_record(sMT) << endl;
}
void MostCalled() {
Profiler p(sMC);
}
void MostExpensive() {
Profiler p(sME);
for (size_t i = 0; i < 10000; ++i) {
cout << ".\b";
}
}
void MostTimeSpent() {
Profiler p(sMT);
for (size_t i = 0; i < 1000; ++i) {
cout << ".\b";
}
}
-------