Back to ST profiling, wont bother profiling the common library for now.

This commit is contained in:
KimLS
2015-01-31 22:21:52 -08:00
parent 444b652c4f
commit 2c6eba93ae
27 changed files with 194 additions and 483 deletions
+1 -3
View File
@@ -15,8 +15,6 @@ SET(eqperf_headers
eqp_profiler_node.h
)
ADD_LIBRARY(eqperf SHARED ${eqperf_sources} ${eqperf_headers})
INSTALL(TARGETS eqperf RUNTIME DESTINATION ${CMAKE_INSTALL_PREFIX})
ADD_LIBRARY(eqperf ${eqperf_sources} ${eqperf_headers})
SET(LIBRARY_OUTPUT_PATH ${PROJECT_BINARY_DIR}/bin)
+6 -6
View File
@@ -7,7 +7,7 @@ EQP::CPU::ST::Event::Event(const char *function_name) {
name_ = nullptr;
start_ = GetCurrentTimer();
EQP::CPU::ST::GetProfiler().EventStarted(function_name_, name_);
identifier_ = EQP::CPU::ST::GetProfiler().EventStarted(function_name_, name_);
}
EQP::CPU::ST::Event::Event(const char *function_name, const char *name) {
@@ -15,13 +15,13 @@ EQP::CPU::ST::Event::Event(const char *function_name, const char *name) {
name_ = name;
start_ = GetCurrentTimer();
EQP::CPU::ST::GetProfiler().EventStarted(function_name_, name_);
identifier_ = EQP::CPU::ST::GetProfiler().EventStarted(function_name_, name_);
}
EQP::CPU::ST::Event::~Event() {
uint64_t end = GetCurrentTimer();
EQP::CPU::ST::GetProfiler().EventFinished(end - start_);
EQP::CPU::ST::GetProfiler().EventFinished(end - start_, identifier_);
}
EQP::CPU::MT::Event::Event(const char *function_name) {
@@ -29,7 +29,7 @@ EQP::CPU::MT::Event::Event(const char *function_name) {
name_ = nullptr;
start_ = GetCurrentTimer();
EQP::CPU::MT::GetProfiler().EventStarted(function_name_, name_);
identifier_ = EQP::CPU::MT::GetProfiler().EventStarted(function_name_, name_);
}
EQP::CPU::MT::Event::Event(const char *function_name, const char *name) {
@@ -37,11 +37,11 @@ EQP::CPU::MT::Event::Event(const char *function_name, const char *name) {
name_ = name;
start_ = GetCurrentTimer();
EQP::CPU::MT::GetProfiler().EventStarted(function_name_, name_);
identifier_ = EQP::CPU::MT::GetProfiler().EventStarted(function_name_, name_);
}
EQP::CPU::MT::Event::~Event() {
uint64_t end = GetCurrentTimer();
EQP::CPU::MT::GetProfiler().EventFinished(end - start_);
EQP::CPU::MT::GetProfiler().EventFinished(end - start_, identifier_);
}
+3
View File
@@ -1,5 +1,6 @@
#pragma once
#include <string>
#include <stdint.h>
#include "eqp_profile_function.h"
@@ -19,6 +20,7 @@ namespace EQP
const char *function_name_;
const char *name_;
uint64_t start_;
std::string identifier_;
};
}
@@ -34,6 +36,7 @@ namespace EQP
const char *function_name_;
const char *name_;
uint64_t start_;
std::string identifier_;
};
}
}
+2 -1
View File
@@ -9,7 +9,8 @@
#endif
#ifdef _MSC_VER
#define EQP_EXPORT __declspec(dllexport)
//#define EQP_EXPORT __declspec(dllexport)
#define EQP_EXPORT
#else
#define EQP_EXPORT
#endif
+42 -15
View File
@@ -4,6 +4,7 @@
#include <mutex>
#include <vector>
#include <algorithm>
#include "../common/uuid.h"
EQP::CPU::ST::Profiler st_profiler;
EQP::CPU::MT::Profiler mt_profiler;
@@ -12,6 +13,7 @@ struct EQP::CPU::MT::Profiler::impl
{
std::mutex lock_;
std::unordered_map<std::thread::id, ThreadInfo*> nodes_;
std::string identifier_;
};
EQP::CPU::ST::Profiler &EQP::CPU::ST::GetProfiler() {
@@ -26,13 +28,14 @@ EQP::CPU::ST::Profiler::Profiler() {
root_ = new ProfilerNode;
root_->SetParent(root_);
current_ = root_;
identifier_ = CreateUUID();
}
EQP::CPU::ST::Profiler::~Profiler() {
delete root_;
}
void EQP::CPU::ST::Profiler::EventStarted(const char *func, const char *name) {
std::string EQP::CPU::ST::Profiler::EventStarted(const char *func, const char *name) {
std::string cur_name = func;
if(name) {
cur_name += " - ";
@@ -48,9 +51,14 @@ void EQP::CPU::ST::Profiler::EventStarted(const char *func, const char *name) {
current_->GetNodes()[cur_name] = t;
current_ = t;
}
return identifier_;
}
void EQP::CPU::ST::Profiler::EventFinished(uint64_t time) {
void EQP::CPU::ST::Profiler::EventFinished(uint64_t time, std::string ident) {
if(ident.compare(identifier_) != 0) {
return;
}
current_->GetTime() += time;
current_->GetCount()++;
current_ = current_->GetParent();
@@ -65,6 +73,7 @@ void EQP::CPU::ST::Profiler::Clear() {
root_->SetTime(0);
root_->SetCount(0);
current_ = root_;
identifier_ = CreateUUID();
}
void EQP::CPU::ST::Profiler::Dump(std::ostream &stream, int num) {
@@ -84,13 +93,21 @@ void EQP::CPU::ST::Profiler::Dump(std::ostream &stream, int num) {
std::sort(sorted_vec.begin(), sorted_vec.end(),
[](const ProfilerNodeDump& a, const ProfilerNodeDump& b) { return a.node->GetTime() > b.node->GetTime(); });
std::streamsize p = stream.precision();
double m_cycles = total / 1000.0;
stream << std::fixed;
stream.precision(2);
stream << m_cycles << "k cycles" << std::endl;
stream.precision(p);
int i = 0;
for(auto &iter : sorted_vec) {
if(num > 0 && i >= num) {
break;
}
iter.node->Dump(stream, iter.name, total, 0, num);
iter.node->Dump(stream, iter.name, total, 1, num);
++i;
}
}
@@ -107,13 +124,14 @@ EQP::CPU::MT::Profiler::ThreadInfo::~ThreadInfo() {
EQP::CPU::MT::Profiler::Profiler() {
imp_ = new impl;
imp_->identifier_ = CreateUUID();
}
EQP::CPU::MT::Profiler::~Profiler() {
delete imp_;
}
void EQP::CPU::MT::Profiler::EventStarted(const char *func, const char *name) {
std::string EQP::CPU::MT::Profiler::EventStarted(const char *func, const char *name) {
std::string cur_name = func;
if(name) {
cur_name += " - ";
@@ -121,7 +139,7 @@ void EQP::CPU::MT::Profiler::EventStarted(const char *func, const char *name) {
}
ThreadInfo *ti = nullptr;
imp_->lock_.lock();
std::lock_guard<std::mutex> lg(imp_->lock_);
auto ti_search = imp_->nodes_.find(std::this_thread::get_id());
if(ti_search == imp_->nodes_.end()) {
ti = new ThreadInfo;
@@ -129,7 +147,6 @@ void EQP::CPU::MT::Profiler::EventStarted(const char *func, const char *name) {
} else {
ti = ti_search->second;
}
imp_->lock_.unlock();
auto search = ti->current_->GetNodes().find(cur_name);
if(search != ti->current_->GetNodes().end()) {
@@ -141,20 +158,24 @@ void EQP::CPU::MT::Profiler::EventStarted(const char *func, const char *name) {
ti->current_->GetNodes()[cur_name] = t;
ti->current_ = t;
}
return imp_->identifier_;
}
void EQP::CPU::MT::Profiler::EventFinished(uint64_t time) {
void EQP::CPU::MT::Profiler::EventFinished(uint64_t time, std::string ident) {
ThreadInfo *ti = nullptr;
imp_->lock_.lock();
std::lock_guard<std::mutex> lg(imp_->lock_);
if(ident.compare(imp_->identifier_) != 0) {
return;
}
auto ti_search = imp_->nodes_.find(std::this_thread::get_id());
if(ti_search == imp_->nodes_.end()) {
imp_->lock_.unlock();
return;
}
else {
ti = ti_search->second;
}
imp_->lock_.unlock();
ti->current_->GetTime() += time;
ti->current_->GetCount()++;
@@ -162,19 +183,18 @@ void EQP::CPU::MT::Profiler::EventFinished(uint64_t time) {
}
void EQP::CPU::MT::Profiler::Clear() {
imp_->lock_.lock();
std::lock_guard<std::mutex> lg(imp_->lock_);
for(auto &iter : imp_->nodes_) {
delete iter.second;
}
imp_->nodes_.clear();
imp_->lock_.unlock();
imp_->identifier_ = CreateUUID();
}
void EQP::CPU::MT::Profiler::Dump(std::ostream &stream, int num) {
imp_->lock_.lock();
std::lock_guard<std::mutex> lg(imp_->lock_);
for(auto &iter : imp_->nodes_) {
stream << "Thread: " << iter.first << std::endl;
uint64_t total = 0;
std::vector<ProfilerNodeDump> sorted_vec;
sorted_vec.reserve(iter.second->root_->GetNodes().size() + 1);
@@ -191,6 +211,14 @@ void EQP::CPU::MT::Profiler::Dump(std::ostream &stream, int num) {
std::sort(sorted_vec.begin(), sorted_vec.end(),
[](const ProfilerNodeDump& a, const ProfilerNodeDump& b) { return a.node->GetTime() > b.node->GetTime(); });
std::streamsize p = stream.precision();
double m_cycles = total / 1000.0;
stream << std::fixed;
stream.precision(2);
stream << "Thread: " << iter.first << ", " << m_cycles << "k cycles" << std::endl;
stream.precision(p);
int i = 0;
for(auto &t_iter : sorted_vec) {
if(num > 0 && i >= num) {
@@ -202,6 +230,5 @@ void EQP::CPU::MT::Profiler::Dump(std::ostream &stream, int num) {
stream << std::endl;
}
imp_->lock_.unlock();
}
+7 -6
View File
@@ -26,13 +26,14 @@ namespace EQP
Profiler();
~Profiler();
void EventStarted(const char *func, const char *name);
void EventFinished(uint64_t time);
void Clear();
std::string EventStarted(const char *func, const char *name);
void EventFinished(uint64_t time, std::string ident);
void Dump(std::ostream &stream, int num = 0);
void Clear();
private:
Node *root_;
Node *current_;
std::string identifier_;
};
EQP_EXPORT Profiler &GetProfiler();
@@ -54,10 +55,10 @@ namespace EQP
Profiler();
~Profiler();
void EventStarted(const char *func, const char *name);
void EventFinished(uint64_t time);
void Clear();
std::string EventStarted(const char *func, const char *name);
void EventFinished(uint64_t time, std::string ident);
void Dump(std::ostream &stream, int num = 0);
void Clear();
private:
struct impl;
impl *imp_;
+2 -2
View File
@@ -21,7 +21,7 @@ void EQP::CPU::ProfilerNode::Dump(std::ostream &stream, const std::string &func,
stream << std::setw(node_level * 2) << " ";
}
double m_cycles = time_ / 1000000.0;
double m_cycles = time_ / 1000.0;
double m_avg_cycles = m_cycles / count_;
double percentage = time_ * 100 / static_cast<double>(total_time);
@@ -29,7 +29,7 @@ void EQP::CPU::ProfilerNode::Dump(std::ostream &stream, const std::string &func,
stream << std::fixed;
stream.precision(2);
stream << m_cycles << "M cycles, " << count_ << " calls, " << m_avg_cycles << "M cycles avg, ";
stream << m_cycles << "k cycles, " << count_ << " calls, " << m_avg_cycles << "k cycles avg, ";
stream << func.c_str() << " ";
stream << percentage << "%";
stream << std::endl;