0
0
mirror of https://github.com/yse/easy_profiler.git synced 2024-12-28 01:04:41 +08:00

(GUI) Added calculation of thread wait time (sum of all context switches)

This commit is contained in:
Victor Zarubkin 2016-12-14 22:16:14 +03:00
parent eafcb40970
commit 7883371166
6 changed files with 33 additions and 68 deletions

View File

@ -194,12 +194,13 @@ namespace profiler {
BlocksTree::children_t sync; ///< List of context-switch events BlocksTree::children_t sync; ///< List of context-switch events
BlocksTree::children_t events; ///< List of events indexes BlocksTree::children_t events; ///< List of events indexes
std::string thread_name; ///< Name of this thread std::string thread_name; ///< Name of this thread
::profiler::timestamp_t active_time; ///< Active time of this thread (sum of all children duration) ::profiler::timestamp_t profiled_time; ///< Profiled time of this thread (sum of all children duration)
::profiler::timestamp_t wait_time; ///< Wait time of this thread (sum of all context switches)
::profiler::thread_id_t thread_id; ///< System Id of this thread ::profiler::thread_id_t thread_id; ///< System Id of this thread
::profiler::block_index_t blocks_number; ///< Total blocks number including their children ::profiler::block_index_t blocks_number; ///< Total blocks number including their children
uint16_t depth; ///< Maximum stack depth (number of levels) uint16_t depth; ///< Maximum stack depth (number of levels)
BlocksTreeRoot() : active_time(0), thread_id(0), blocks_number(0), depth(0) BlocksTreeRoot() : profiled_time(0), wait_time(0), thread_id(0), blocks_number(0), depth(0)
{ {
} }
@ -208,7 +209,8 @@ namespace profiler {
, sync(::std::move(that.sync)) , sync(::std::move(that.sync))
, events(::std::move(that.events)) , events(::std::move(that.events))
, thread_name(::std::move(that.thread_name)) , thread_name(::std::move(that.thread_name))
, active_time(that.active_time) , profiled_time(that.profiled_time)
, wait_time(that.wait_time)
, thread_id(that.thread_id) , thread_id(that.thread_id)
, blocks_number(that.blocks_number) , blocks_number(that.blocks_number)
, depth(that.depth) , depth(that.depth)
@ -221,7 +223,8 @@ namespace profiler {
sync = ::std::move(that.sync); sync = ::std::move(that.sync);
events = ::std::move(that.events); events = ::std::move(that.events);
thread_name = ::std::move(that.thread_name); thread_name = ::std::move(that.thread_name);
active_time = that.active_time; profiled_time = that.profiled_time;
wait_time = that.wait_time;
thread_id = that.thread_id; thread_id = that.thread_id;
blocks_number = that.blocks_number; blocks_number = that.blocks_number;
depth = that.depth; depth = that.depth;
@ -346,51 +349,6 @@ namespace profiler {
////////////////////////////////////////////////////////////////////////// //////////////////////////////////////////////////////////////////////////
struct FileData
{
::profiler::SerializedData serialized_blocks;
::profiler::SerializedData serialized_descriptors;
::std::vector<::profiler::thread_id_t> threads_order;
::profiler::timestamp_t begin_time = 0ULL;
::profiler::timestamp_t end_time = 0ULL;
int64_t cpu_frequency = 0LL;
uint32_t total_blocks_number = 0;
uint32_t total_descriptors_number = 0;
FileData() = default;
FileData(FileData&& _other)
: serialized_blocks(::std::move(_other.serialized_blocks))
, serialized_descriptors(::std::move(_other.serialized_descriptors))
, threads_order(::std::move(_other.threads_order))
, begin_time(_other.begin_time)
, end_time(_other.end_time)
, cpu_frequency(_other.cpu_frequency)
, total_blocks_number(_other.total_blocks_number)
, total_descriptors_number(_other.total_descriptors_number)
{
}
FileData& operator = (FileData&& _other)
{
serialized_blocks = ::std::move(_other.serialized_blocks);
serialized_descriptors = ::std::move(_other.serialized_descriptors);
threads_order = ::std::move(_other.threads_order);
begin_time = _other.begin_time;
end_time = _other.end_time;
cpu_frequency = _other.cpu_frequency;
total_blocks_number = _other.total_blocks_number;
total_descriptors_number = _other.total_descriptors_number;
return *this;
}
private:
FileData(const FileData&) = delete;
FileData& operator = (const FileData&) = delete;
};
//////////////////////////////////////////////////////////////////////////
typedef ::std::vector<SerializedBlockDescriptor*> descriptors_list_t; typedef ::std::vector<SerializedBlockDescriptor*> descriptors_list_t;
} // END of namespace profiler. } // END of namespace profiler.

View File

@ -532,6 +532,7 @@ extern "C" {
tree.node = baseData; tree.node = baseData;
const auto block_index = blocks_counter++; const auto block_index = blocks_counter++;
root.wait_time += baseData->duration();
root.sync.emplace_back(block_index); root.sync.emplace_back(block_index);
} }
@ -741,7 +742,7 @@ extern "C" {
if (root.depth < frame.depth) if (root.depth < frame.depth)
root.depth = frame.depth; root.depth = frame.depth;
root.active_time += frame.node->duration(); root.profiled_time += frame.node->duration();
} }
++root.depth; ++root.depth;
@ -774,7 +775,7 @@ extern "C" {
auto& frame = blocks[i]; auto& frame = blocks[i];
if (root.depth < frame.depth) if (root.depth < frame.depth)
root.depth = frame.depth; root.depth = frame.depth;
root.active_time += frame.node->duration(); root.profiled_time += frame.node->duration();
} }
++root.depth; ++root.depth;

View File

@ -427,8 +427,8 @@ void EasyGraphicsView::setTree(const ::profiler::thread_blocks_tree_t& _blocksTr
if (finish < timefinish) if (finish < timefinish)
finish = timefinish; finish = timefinish;
if (t.active_time > busyTime) { if (t.profiled_time > busyTime) {
busyTime = t.active_time; busyTime = t.profiled_time;
longestTree = threadTree.first; longestTree = threadTree.first;
} }
@ -1442,10 +1442,10 @@ void EasyGraphicsView::onIdleTimeout()
lay->addWidget(new QLabel("Thread", widget), row + 1, 1, Qt::AlignHCenter); lay->addWidget(new QLabel("Thread", widget), row + 1, 1, Qt::AlignHCenter);
auto percent = ::profiler_gui::percentReal(duration, item->root()->active_time); auto percent = ::profiler_gui::percentReal(duration, item->root()->profiled_time);
lay->addWidget(new QLabel(0.005 < percent && percent < 0.5001 ? QString::number(percent, 'f', 2) : QString::number(static_cast<int>(0.5 + percent)), widget), row + 2, 1, Qt::AlignHCenter); lay->addWidget(new QLabel(0.005 < percent && percent < 0.5001 ? QString::number(percent, 'f', 2) : QString::number(static_cast<int>(0.5 + percent)), widget), row + 2, 1, Qt::AlignHCenter);
lay->addWidget(new QLabel(QString::number(::profiler_gui::percent(itemBlock.per_thread_stats->total_duration, item->root()->active_time)), widget), row + 3, 1, Qt::AlignHCenter); lay->addWidget(new QLabel(QString::number(::profiler_gui::percent(itemBlock.per_thread_stats->total_duration, item->root()->profiled_time)), widget), row + 3, 1, Qt::AlignHCenter);
lay->addWidget(new QLabel(QString::number(itemBlock.per_thread_stats->calls_number), widget), row + 4, 1, Qt::AlignHCenter); lay->addWidget(new QLabel(QString::number(itemBlock.per_thread_stats->calls_number), widget), row + 4, 1, Qt::AlignHCenter);

View File

@ -228,7 +228,8 @@ void EasyGraphicsSliderItem::setColor(const QColor& _color)
EasyHystogramItem::EasyHystogramItem() : Parent(nullptr) EasyHystogramItem::EasyHystogramItem() : Parent(nullptr)
, m_threadDuration(0) , m_threadDuration(0)
, m_threadActiveTime(0) , m_threadProfiledTime(0)
, m_threadWaitTime(0)
, m_pSource(nullptr) , m_pSource(nullptr)
, m_temporaryImage(nullptr) , m_temporaryImage(nullptr)
, m_maxDuration(0) , m_maxDuration(0)
@ -451,10 +452,12 @@ void EasyHystogramItem::paintByPtr(QPainter* _painter)
_painter->setPen(Qt::black); _painter->setPen(Qt::black);
rect.setRect(0, bottom + 2, width, widget->defaultFontHeight()); rect.setRect(0, bottom + 2, width, widget->defaultFontHeight());
_painter->drawText(rect, Qt::AlignHCenter | Qt::TextDontClip, QString("%1 | duration: %2 | active time: %3 (%4%) | %5 blocks (%6 events)").arg(m_threadName) _painter->drawText(rect, Qt::AlignHCenter | Qt::TextDontClip, QString("%1 | duration: %2 | profiled time: %3 (%4%) | wait time: %5 (%6%) | %7 blocks (%8 events)").arg(m_threadName)
.arg(::profiler_gui::timeStringRealNs(EASY_GLOBALS.time_units, m_threadDuration)) .arg(::profiler_gui::timeStringRealNs(EASY_GLOBALS.time_units, m_threadDuration))
.arg(::profiler_gui::timeStringRealNs(EASY_GLOBALS.time_units, m_threadActiveTime)) .arg(::profiler_gui::timeStringRealNs(EASY_GLOBALS.time_units, m_threadProfiledTime))
.arg(m_threadDuration ? QString::number(100. * (double)m_threadActiveTime / (double)m_threadDuration, 'f', 2) : QString("0")) .arg(m_threadDuration ? QString::number(100. * (double)m_threadProfiledTime / (double)m_threadDuration, 'f', 2) : QString("0"))
.arg(::profiler_gui::timeStringRealNs(EASY_GLOBALS.time_units, m_threadWaitTime))
.arg(m_threadDuration ? QString::number(100. * (double)m_threadWaitTime / (double)m_threadDuration, 'f', 2) : QString("0"))
.arg(m_pProfilerThread->blocks_number) .arg(m_pProfilerThread->blocks_number)
.arg(m_pProfilerThread->events.size())); .arg(m_pProfilerThread->events.size()));
@ -670,9 +673,9 @@ void EasyHystogramItem::paintById(QPainter* _painter)
const auto name = *item->tree.node->name() != 0 ? item->tree.node->name() : easyDescriptor(item->tree.node->id()).name(); const auto name = *item->tree.node->name() != 0 ? item->tree.node->name() : easyDescriptor(item->tree.node->id()).name();
if (item->tree.per_thread_stats != nullptr) if (item->tree.per_thread_stats != nullptr)
{ {
_painter->drawText(rect, Qt::AlignHCenter | Qt::TextDontClip, QString("%1 | %2 | %3 calls | %4% of thread active time").arg(m_threadName).arg(name) _painter->drawText(rect, Qt::AlignHCenter | Qt::TextDontClip, QString("%1 | %2 | %3 calls | %4% of thread profiled time").arg(m_threadName).arg(name)
.arg(item->tree.per_thread_stats->calls_number) .arg(item->tree.per_thread_stats->calls_number)
.arg(m_threadActiveTime ? QString::number(100. * (double)item->tree.per_thread_stats->total_duration / (double)m_threadActiveTime, 'f', 2) : QString("100"))); .arg(m_threadProfiledTime ? QString::number(100. * (double)item->tree.per_thread_stats->total_duration / (double)m_threadProfiledTime, 'f', 2) : QString("100")));
} }
else else
{ {
@ -768,7 +771,8 @@ void EasyHystogramItem::setSource(::profiler::thread_id_t _thread_id, const ::pr
m_threadDuration = 0; m_threadDuration = 0;
else else
m_threadDuration = easyBlock(root.children.back()).tree.node->end() - easyBlock(root.children.front()).tree.node->begin(); m_threadDuration = easyBlock(root.children.back()).tree.node->end() - easyBlock(root.children.front()).tree.node->begin();
m_threadActiveTime = root.active_time; m_threadProfiledTime = root.profiled_time;
m_threadWaitTime = root.wait_time;
m_pProfilerThread = &root; m_pProfilerThread = &root;
@ -816,7 +820,8 @@ void EasyHystogramItem::setSource(::profiler::thread_id_t _thread_id, ::profiler
m_threadDuration = 0; m_threadDuration = 0;
else else
m_threadDuration = easyBlock(root.children.back()).tree.node->end() - easyBlock(root.children.front()).tree.node->begin(); m_threadDuration = easyBlock(root.children.back()).tree.node->end() - easyBlock(root.children.front()).tree.node->begin();
m_threadActiveTime = root.active_time; m_threadProfiledTime = root.profiled_time;
m_threadWaitTime = root.wait_time;
m_pProfilerThread = &root; m_pProfilerThread = &root;

View File

@ -144,7 +144,8 @@ class EasyHystogramItem : public QGraphicsItem
EasyQTimer m_timer; EasyQTimer m_timer;
::std::thread m_workerThread; ::std::thread m_workerThread;
::profiler::timestamp_t m_threadDuration; ::profiler::timestamp_t m_threadDuration;
::profiler::timestamp_t m_threadActiveTime; ::profiler::timestamp_t m_threadProfiledTime;
::profiler::timestamp_t m_threadWaitTime;
const ::profiler_gui::EasyItems* m_pSource; const ::profiler_gui::EasyItems* m_pSource;
QImage* m_temporaryImage; QImage* m_temporaryImage;
const ::profiler::BlocksTreeRoot* m_pProfilerThread; const ::profiler::BlocksTreeRoot* m_pProfilerThread;

View File

@ -208,7 +208,7 @@ void FillTreeClass<T>::setTreeInternal1(T& _safelocker, Items& _items, ThreadedI
//_items.push_back(item); //_items.push_back(item);
item->setTimeSmart(COL_SELF_DURATION, _units, root.active_time); item->setTimeSmart(COL_SELF_DURATION, _units, root.profiled_time);
::profiler::timestamp_t children_duration = 0; ::profiler::timestamp_t children_duration = 0;
const auto children_items_number = FillTreeClass<T>::setTreeInternal(_safelocker, _items, _beginTime, root.children, item, nullptr, item, _beginTime, finishtime + 1000000000ULL, false, children_duration, _colorizeRows, _addZeroBlocks, _units); const auto children_items_number = FillTreeClass<T>::setTreeInternal(_safelocker, _items, _beginTime, root.children, item, nullptr, item, _beginTime, finishtime + 1000000000ULL, false, children_duration, _colorizeRows, _addZeroBlocks, _units);
@ -291,7 +291,7 @@ void FillTreeClass<T>::setTreeInternal2(T& _safelocker, Items& _items, ThreadedI
thread_item->setTextColor(::profiler_gui::SELECTED_THREAD_FOREGROUND); thread_item->setTextColor(::profiler_gui::SELECTED_THREAD_FOREGROUND);
// Sum of all children durations: // Sum of all children durations:
thread_item->setTimeSmart(COL_SELF_DURATION, _units, block.root->active_time); thread_item->setTimeSmart(COL_SELF_DURATION, _units, block.root->profiled_time);
threadsMap.insert(::std::make_pair(block.root->thread_id, thread_item)); threadsMap.insert(::std::make_pair(block.root->thread_id, thread_item));
} }
@ -307,7 +307,7 @@ void FillTreeClass<T>::setTreeInternal2(T& _safelocker, Items& _items, ThreadedI
item->setData(COL_PERCENT_PER_FRAME, Qt::UserRole, 0); item->setData(COL_PERCENT_PER_FRAME, Qt::UserRole, 0);
auto percentage_per_thread = ::profiler_gui::percent(duration, block.root->active_time); auto percentage_per_thread = ::profiler_gui::percent(duration, block.root->profiled_time);
item->setData(COL_PERCENT_PER_PARENT, Qt::UserRole, percentage_per_thread); item->setData(COL_PERCENT_PER_PARENT, Qt::UserRole, percentage_per_thread);
item->setText(COL_PERCENT_PER_PARENT, QString::number(percentage_per_thread)); item->setText(COL_PERCENT_PER_PARENT, QString::number(percentage_per_thread));
@ -329,7 +329,7 @@ void FillTreeClass<T>::setTreeInternal2(T& _safelocker, Items& _items, ThreadedI
item->setData(COL_NCALLS_PER_THREAD, Qt::UserRole, per_thread_stats->calls_number); item->setData(COL_NCALLS_PER_THREAD, Qt::UserRole, per_thread_stats->calls_number);
item->setText(COL_NCALLS_PER_THREAD, QString::number(per_thread_stats->calls_number)); item->setText(COL_NCALLS_PER_THREAD, QString::number(per_thread_stats->calls_number));
percentage_per_thread = ::profiler_gui::percent(per_thread_stats->total_duration, block.root->active_time); percentage_per_thread = ::profiler_gui::percent(per_thread_stats->total_duration, block.root->profiled_time);
item->setData(COL_PERCENT_SUM_PER_THREAD, Qt::UserRole, percentage_per_thread); item->setData(COL_PERCENT_SUM_PER_THREAD, Qt::UserRole, percentage_per_thread);
item->setText(COL_PERCENT_SUM_PER_THREAD, QString::number(percentage_per_thread)); item->setText(COL_PERCENT_SUM_PER_THREAD, QString::number(percentage_per_thread));