#include <base/config.h>
#include <base/conditional_ostream.h>
+
#include <string>
-#include <vector>
+#include <list>
+#include <map>
DEAL_II_NAMESPACE_OPEN
+//TODO: The following class is not thread-safe
/**
* This class can be used to generate formatted output from time
* measurements of different subsections in a program. It is possible to
class TimerOutput
{
public:
- // Sets whether to generate output every
- // time we exit a section, just in the
- // end, or both.
+ /**
+ * Sets whether to generate output every
+ * time we exit a section, just in the
+ * end, or both.
+ */
enum OutputFrequency {every_call, summary, every_call_and_summary}
- output_frequency;
+ output_frequency;
- // Sets whether to show CPU times, wall
- // times, or both CPU and wall times.
+ /**
+ * Sets whether to show CPU times, wall
+ * times, or both CPU and wall times.
+ */
enum OutputType {cpu_times, wall_times, cpu_and_wall_times}
- output_type;
-
- // Constructor that takes std::cout as
- // output stream.
+ output_type;
+
+ /**
+ * Constructor that takes std::cout as
+ * output stream.
+ */
TimerOutput (std::ostream &stream,
const enum OutputFrequency output_frequency,
const enum OutputType output_type);
- // Constructor that takes a
- // ConditionalOStream to write output to.
+ /**
+ * Constructor that takes a
+ * ConditionalOStream to write output to.
+ */
TimerOutput (ConditionalOStream &stream,
const enum OutputFrequency output_frequency,
const enum OutputType output_type);
- // Destructor. Calls print_summary() in
- // case the option for writing the
- // summary output is set.
+ /**
+ * Destructor. Calls print_summary() in
+ * case the option for writing the
+ * summary output is set.
+ */
~TimerOutput();
- // Open a section by given a string name
- // of it. In case the name already
- // exists, that section is done once
- // again.
+ /**
+ * Open a section by given a string name
+ * of it. In case the name already
+ * exists, that section is done once
+ * again.
+ */
void enter_section (const std::string §ion_name);
- // Leave a section. If no name is given,
- // the last section that was entered is
- // left.
+ /**
+ * Leave a section. If no name is given,
+ * the last section that was entered is
+ * left.
+ */
void exit_section (const std::string §ion_name = std::string());
- // Print a formatted table that
- // summarizes the time consumed in the
- // various sections.
+ /**
+ * Print a formatted table that
+ * summarizes the time consumed in the
+ * various sections.
+ */
void print_summary ();
private:
+ /**
+ * A timer object for the overall
+ * run time. If we are using MPI,
+ * this timer also accumulates
+ * over all MPI processes.
+ */
Timer timer_all;
- std::vector<Timer> section_timers;
- std::vector<std::string> section_names;
- std::vector<double> section_total_cpu_times;
- std::vector<double> section_total_wall_times;
- std::vector<unsigned int> section_n_calls;
+
+ /**
+ * A structure that groups all
+ * information that we collect
+ * about each of the sections.
+ */
+ struct Section
+ {
+ Timer timer;
+ double total_cpu_time;
+ double total_wall_time;
+ unsigned int n_calls;
+ };
+
+ /**
+ * A list of all the sections and
+ * their information.
+ */
+ std::map<std::string, Section> sections;
+
+ /**
+ * The stream object to which we
+ * are to output.
+ */
ConditionalOStream out_stream;
- std::vector<unsigned int> active_sections;
+
+ /**
+ * A list of the sections that
+ * have been entered and not
+ * exited. The list is kept in
+ * the order in which sections
+ * have been entered, but
+ * elements may be removed in the
+ * middle if an argument is given
+ * to the exit_section()
+ * function.
+ */
+ std::list<std::string> active_sections;
};
DEAL_II_NAMESPACE_CLOSE
Assert (section_name.empty() == false,
ExcMessage ("Section string is empty."));
- unsigned int this_section_number = numbers::invalid_unsigned_int;
-
- // check whether the requested section
- // already exists
- for (unsigned int i=0; i<section_names.size(); ++i)
+ Assert (std::find (active_sections.begin(), active_sections.end(),
+ section_name) == active_sections.end(),
+ ExcMessage ("Cannot enter the already active section."));
+
+ if (sections.find (section_name) == sections.end())
{
- // if we found it, we have to have the
- // index into which we write the
- // data. ensure that the section was not
- // active before to avoid any mess
- if (section_names[i].compare (section_name) == 0)
- {
- this_section_number = i;
- for (unsigned int j=0; j<active_sections.size(); ++j)
- {
- if (active_sections[j] == i)
- {
-#ifdef DEBUG
- std::string exc_text = "Cannot enter the already active section "
- + section_name;
- Assert (active_sections[j] != i, ExcMessage (exc_text.data()));
-#endif
- exit_section(section_name);
- }
- }
- break;
- }
+ sections[section_name].total_cpu_time = 0;
+ sections[section_name].total_wall_time = 0;
+ sections[section_name].n_calls = 0;
}
- // in case this is a new section, enlarge
- // our data storage by one, otherwise
- // just reset the timer
- if (this_section_number == numbers::invalid_unsigned_int)
- {
- section_names.push_back(section_name);
- section_total_cpu_times.push_back (0.);
- section_total_wall_times.push_back (0.);
- section_timers.push_back (Timer());
- section_n_calls.push_back (0);
- this_section_number = section_names.size() - 1;
- }
- else
- {
- section_timers[this_section_number].reset();
- section_timers[this_section_number].start();
- }
+ sections[section_name].timer.reset();
+ sections[section_name].timer.start();
+ sections[section_name].n_calls++;
- // now turn the current section into the
- // list of active sections and increase
- // the counter for that section
- active_sections.push_back (this_section_number);
- section_n_calls[this_section_number]++;
+ active_sections.push_back (section_name);
}
void
TimerOutput::exit_section (const std::string §ion_name)
{
- // if no string is given, exit the last
- // active section.
- unsigned int active_index_to_delete = numbers::invalid_unsigned_int;
- if (section_name.empty() == true)
- active_index_to_delete = active_sections.size() - 1;
- // if we got a string, we need to find
- // the index in the list of active
- // functions
- else
- {
- for (unsigned int i=0; i<active_sections.size(); ++i)
- if (section_names[active_sections[i]].compare (section_name) == 0)
- {
- active_index_to_delete = i;
- break;
- }
- }
-
- Assert (active_index_to_delete != numbers::invalid_unsigned_int,
+ Assert (sections.find (section_name) != sections.end(),
ExcMessage ("Cannot delete a section that was never created."));
-
- const unsigned int section_to_exit = active_sections[active_index_to_delete];
-
- Assert (section_to_exit < section_names.size(),
- ExcInternalError());
-
- // stop the timer for this section.
- section_timers[section_to_exit].stop();
- section_total_wall_times[section_to_exit] += section_timers[section_to_exit].wall_time();
-
- // get cpu time. on MPI systems, add the
- // local contributions.
- //
- // TODO: this should rather be in the Timer
- // class itself, shouldn't it?
- double cpu_time = section_timers[section_to_exit]();
+ Assert (std::find (active_sections.begin(), active_sections.end(),
+ section_name) == active_sections.end(),
+ ExcMessage ("Cannot delete a section that has not been entered."));
+
+ // if no string is given, exit the last
+ // active section.
+ const std::string actual_section_name = (section_name == "" ?
+ active_sections.back () :
+ section_name);
+
+ sections[actual_section_name].timer.stop();
+ sections[actual_section_name].total_wall_time += sections[section_name].timer.wall_time();
+
+ // get cpu time. on MPI
+ // systems, add the local
+ // contributions.
+ //
+ // TODO: this should rather be
+ // in the Timer class itself,
+ // shouldn't it?
+ double cpu_time = sections[section_name].timer();
{
// On MPI, sum up all the local CPU
cpu_time = total_cpu_time;
}
#endif
- section_total_cpu_times[section_to_exit] += cpu_time;
+ sections[actual_section_name].total_cpu_time += cpu_time;
}
std::ostringstream cpu;
cpu << cpu_time << "s";
std::ostringstream wall;
- wall << section_timers[section_to_exit].wall_time() << "s";
+ wall << sections[actual_section_name].timer.wall_time() << "s";
if (output_type == cpu_times)
output_time = " CPU time: " + cpu.str();
else if (output_type == wall_times)
else
output_time = ", CPU/wall time: " + cpu.str() + " / " + wall.str() + ".";
- out_stream << section_names[section_to_exit] << output_time
+ out_stream << actual_section_name << output_time
<< std::endl;
}
// delete the index from the list of
// active ones
- std::vector<unsigned int>::iterator position_to_delete
- = active_sections.begin() + active_index_to_delete;
- active_sections.erase(position_to_delete);
+ active_sections.erase (std::find (active_sections.begin(), active_sections.end(),
+ section_name));
}
// generated a lot of overhead in this
// function.
double check_time = 0.;
- for (unsigned int i=0; i<section_names.size(); ++i)
- {
- check_time += section_total_cpu_times[i];
- }
+ for (std::map<std::string, Section>::const_iterator
+ i = sections.begin(); i!=sections.end(); ++i)
+ check_time += i->second.total_cpu_time;
+
if (check_time > total_cpu_time)
{
total_cpu_time = check_time;
out_stream << " CPU time " << " | % of total |\n";
out_stream << "+---------------------------------------------+------------"
<< "+------------+";
- for (unsigned int i=0; i<section_names.size(); ++i)
+ for (std::map<std::string, Section>::const_iterator
+ i = sections.begin(); i!=sections.end(); ++i)
{
- std::string name_out = section_names[i];
+ std::string name_out = i->first;
// resize the array so that it is always
// of the same size
out_stream << "| " << name_out;
out_stream << "| ";
std::cout.width(9);
- out_stream << section_n_calls[i] << " |";
+ out_stream << i->second.n_calls << " |";
std::cout.width(10);
std::cout.precision(3);
- out_stream << section_total_cpu_times[i] << "s |";
+ out_stream << i->second.total_cpu_time << "s |";
std::cout.width(10);
std::cout.precision(2);
- out_stream << section_total_cpu_times[i]/total_cpu_time * 100 << "% |";
+ out_stream << i->second.total_cpu_time/total_cpu_time * 100 << "% |";
}
out_stream << std::endl
<< "+---------------------------------------------+"
// generated a lot of overhead in this
// function.
double check_time = 0.;
- for (unsigned int i=0; i<section_names.size(); ++i)
- {
- check_time += section_total_wall_times[i];
- }
+ for (std::map<std::string, Section>::const_iterator
+ i = sections.begin(); i!=sections.end(); ++i)
+ check_time += i->second.total_wall_time;
+
if (check_time > total_wall_time)
{
total_wall_time = check_time;
out_stream << " CPU time " << " | % of total |\n";
out_stream << "+---------------------------------------------+------------"
<< "+------------+";
- for (unsigned int i=0; i<section_names.size(); ++i)
+ for (std::map<std::string, Section>::const_iterator
+ i = sections.begin(); i!=sections.end(); ++i)
{
- std::string name_out = section_names[i];
+ std::string name_out = i->first;
// resize the array so that it is always
// of the same size
out_stream << "| " << name_out;
out_stream << "| ";
std::cout.width(9);
- out_stream << section_n_calls[i] << " |";
+ out_stream << i->second.n_calls << " |";
std::cout.width(10);
std::cout.precision(3);
- out_stream << section_total_wall_times[i] << "s |";
+ out_stream << i->second.total_wall_time << "s |";
std::cout.width(10);
std::cout.precision(2);
- out_stream << section_total_wall_times[i]/total_wall_time * 100 << "% |";
+ out_stream << i->second.total_wall_time/total_wall_time * 100 << "% |";
}
out_stream << std::endl
<< "+---------------------------------------------+"