void netlist_t::print_stats() const
{
if (nperftime_t::enabled)
{
std::vector<size_t> index;
for (size_t i=0; i<m_devices.size(); i++)
index.push_back(i);
std::sort(index.begin(), index.end(),
[&](size_t i1, size_t i2) { return m_devices[i1]->m_stat_total_time.total() < m_devices[i2]->m_stat_total_time.total(); });
nperftime_t::type total_time(0);
uint_least64_t total_count(0);
for (auto & j : index)
{
auto entry = m_devices[j].get();
log().verbose("Device {1:20} : {2:12} {3:12} {4:15} {5:12}", entry->name(),
entry->m_stat_call_count(), entry->m_stat_total_time.count(),
entry->m_stat_total_time.total(), entry->m_stat_inc_active());
total_time += entry->m_stat_total_time.total();
total_count += entry->m_stat_total_time.count();
}
nperftime_t overhead;
nperftime_t test;
overhead.start();
for (int j=0; j<100000;j++)
{
test.start();
test.stop();
}
overhead.stop();
nperftime_t::type total_overhead = overhead()
* static_cast<nperftime_t::type>(total_count)
/ static_cast<nperftime_t::type>(200000);
log().verbose("Queue Pushes {1:15}", queue().m_prof_call());
log().verbose("Queue Moves {1:15}", queue().m_prof_sortmove());
log().verbose("Total loop {1:15}", m_stat_mainloop());
/* Only one serialization should be counted in total time */
/* But two are contained in m_stat_mainloop */
log().verbose("Total devices {1:15}", total_time);
log().verbose("");
log().verbose("Take the next lines with a grain of salt. They depend on the measurement implementation.");
log().verbose("Total overhead {1:15}", total_overhead);
nperftime_t::type overhead_per_pop = (m_stat_mainloop()-2*total_overhead - (total_time - total_overhead))
/ static_cast<nperftime_t::type>(queue().m_prof_call());
log().verbose("Overhead per pop {1:11}", overhead_per_pop );
log().verbose("");
for (auto &entry : m_devices)
{
if (entry->m_stat_inc_active() > 3 * entry->m_stat_total_time.count())
log().verbose("HINT({}, NO_DEACTIVATE)", entry->name());
}
}
}
void netlist_t::print_stats() const
{
if (nperftime_t<NL_KEEP_STATISTICS>::enabled)
{
std::vector<size_t> index;
for (size_t i=0; i < m_state->m_devices.size(); i++)
index.push_back(i);
std::sort(index.begin(), index.end(),
[&](size_t i1, size_t i2) { return m_state->m_devices[i1].second->m_stat_total_time.total() < m_state->m_devices[i2].second->m_stat_total_time.total(); });
nperftime_t<NL_KEEP_STATISTICS>::type total_time(0);
nperftime_t<NL_KEEP_STATISTICS>::ctype total_count(0);
for (auto & j : index)
{
auto entry = m_state->m_devices[j].second.get();
log().verbose("Device {1:20} : {2:12} {3:12} {4:15} {5:12}", entry->name(),
entry->m_stat_call_count(), entry->m_stat_total_time.count(),
entry->m_stat_total_time.total(), entry->m_stat_inc_active());
total_time += entry->m_stat_total_time.total();
total_count += entry->m_stat_total_time.count();
}
log().verbose("Total calls : {1:12} {2:12} {3:12}", total_count,
total_time, total_time / static_cast<decltype(total_time)>(total_count));
nperftime_t<NL_KEEP_STATISTICS> overhead;
nperftime_t<NL_KEEP_STATISTICS> test;
{
auto overhead_guard(overhead.guard());
for (int j=0; j<100000;j++)
{
auto test_guard(test.guard());
}
}
nperftime_t<NL_KEEP_STATISTICS>::type total_overhead = overhead()
* static_cast<nperftime_t<NL_KEEP_STATISTICS>::type>(total_count)
/ static_cast<nperftime_t<NL_KEEP_STATISTICS>::type>(200000);
log().verbose("Queue Pushes {1:15}", m_queue.m_prof_call());
log().verbose("Queue Moves {1:15}", m_queue.m_prof_sortmove());
log().verbose("Queue Removes {1:15}", m_queue.m_prof_remove());
log().verbose("Queue Retimes {1:15}", m_queue.m_prof_retime());
log().verbose("Total loop {1:15}", m_stat_mainloop());
/* Only one serialization should be counted in total time */
/* But two are contained in m_stat_mainloop */
log().verbose("Total devices {1:15}", total_time);
log().verbose("");
log().verbose("Take the next lines with a grain of salt. They depend on the measurement implementation.");
log().verbose("Total overhead {1:15}", total_overhead);
nperftime_t<NL_KEEP_STATISTICS>::type overhead_per_pop = (m_stat_mainloop()-2*total_overhead - (total_time - total_overhead))
/ static_cast<nperftime_t<NL_KEEP_STATISTICS>::type>(m_queue.m_prof_call());
log().verbose("Overhead per pop {1:11}", overhead_per_pop );
log().verbose("");
auto trigger = total_count * 200 / 1000000; // 200 ppm
for (auto &entry : m_state->m_devices)
{
auto ep = entry.second.get();
// Factor of 3 offers best performace increase
if (ep->m_stat_inc_active() > 3 * ep->m_stat_total_time.count()
&& ep->m_stat_inc_active() > trigger)
log().verbose("HINT({}, NO_DEACTIVATE) // {} {} {}", ep->name(),
static_cast<double>(ep->m_stat_inc_active()) / static_cast<double>(ep->m_stat_total_time.count()),
ep->m_stat_inc_active(), ep->m_stat_total_time.count());
}
}
}
