From ef58c3dd4120ebee0f4cf708b6ff64a0b0ee810b Mon Sep 17 00:00:00 2001 From: Rene Milk <rene.milk@uni-muenster.de> Date: Sun, 9 Jan 2011 02:09:36 +0100 Subject: [PATCH] profiler: fix mysterious memory corruption error in ScopeTiming usage --- stuff/profiler.hh | 65 ++++++++++++++++++++++++++++++----------------- 1 file changed, 42 insertions(+), 23 deletions(-) diff --git a/stuff/profiler.hh b/stuff/profiler.hh index 2ed1899d8..4d1b09a0d 100644 --- a/stuff/profiler.hh +++ b/stuff/profiler.hh @@ -25,11 +25,19 @@ struct TimingData TimingData(const std::string _name, const clock_t _start) : start(_start) , end((clock_t)0.0) - , name(_name){}; + , name(_name) + { + } TimingData() : start((clock_t)0.0) , end((clock_t)0.0) - , name("blank"){}; + , name("blank") + { + } + long delta() const + { + return long(end - start); + } }; /** \brief simple inline profiling class @@ -51,53 +59,63 @@ protected: { } - typedef std::vector<TimingData> TimingVector; - typedef std::map<std::string, TimingVector> DataMap; + typedef std::map<std::string, std::pair<bool, TimingData>> KnownTimersMap; + typedef std::map<std::string, long> DataMap; typedef std::vector<DataMap> MapVector; public: //! set this to begin a named section void StartTiming(const std::string section_name) { - TimingData td(section_name, clock()); if (m_cur_run_num >= m_timings.size()) { m_timings.push_back(DataMap()); m_total_runs++; } - (m_timings[m_cur_run_num])[section_name].push_back(td); + + KnownTimersMap::iterator section = known_timers_map_.find(section_name); + if (section != known_timers_map_.end()) { + if (section->second.first) // timer currently running + return; + section->second.first = true; // set active, start with new + section->second.second = TimingData(section_name, clock()); + } else { + // init new section + known_timers_map_[section_name] = std::make_pair(true, TimingData(section_name, clock())); + } } //! stop named section's counter void StopTiming(const std::string section_name) { assert(m_cur_run_num < m_timings.size()); - if ((m_timings[m_cur_run_num])[section_name].size() < 1) + if (known_timers_map_.find(section_name) == known_timers_map_.end()) DUNE_THROW(Dune::RangeError, "trying to stop timer " << section_name << " that wasn't started\n"); - (m_timings[m_cur_run_num])[section_name].back().end = clock(); + + known_timers_map_[section_name].first = false; + known_timers_map_[section_name].second.end = clock(); + DataMap& current_data = m_timings[m_cur_run_num]; + if (current_data.find(section_name) == current_data.end()) + current_data[section_name] = known_timers_map_[section_name].second.delta(); + else + current_data[section_name] += known_timers_map_[section_name].second.delta(); } //! get runtime of section in seconds long GetTiming(const std::string section_name) const { - std::cerr << "SEC " << section_name << std::endl; + return GetTiming(section_name, m_cur_run_num); + } + + long GetTiming(const std::string section_name, const int run_number) const + { assert(m_cur_run_num < m_timings.size()); - const DataMap& data = m_timings[m_cur_run_num]; + const DataMap& data = m_timings[run_number]; DataMap::const_iterator section = data.find(section_name); if (section == data.end()) { ASSERT_EXCEPTION(false, "no timer found: " + section_name); return -1; } - return GetTiming(section->second); - } - long GetTiming(const TimingVector& timing_vector) const - { - TimingVector::const_iterator endIt = timing_vector.end(); - TimingVector::const_iterator it = timing_vector.begin(); - long diff = 0; - for (; it != endIt; ++it) { - diff += it->end - it->start; - } - return long(diff / double(CLOCKS_PER_SEC)); + return long(section->second / double(CLOCKS_PER_SEC)); } /** output to currently pre-defined (csv) file, does not output individual run results, but average over all recorded @@ -152,7 +170,7 @@ public: } //! a utility class to time a limited scope of code - class ScopedTiming + class ScopedTiming : public boost::noncopyable { const std::string section_name_; @@ -175,6 +193,7 @@ protected: // debug counter, only outputted in debug mode std::map<int, int> m_count; clock_t init_time_; + KnownTimersMap known_timers_map_; static Profiler& instance() { @@ -300,7 +319,7 @@ long Profiler::OutputCommon(CollectiveCommunication& comm, InfoContainer& run_in const DataMap& data_map = *ti_it; for (DataMap::const_iterator it = data_map.begin(); it != data_map.end(); ++it) { - long clock_count = GetTiming(it->second); + long clock_count = GetTiming(it->first, idx); clock_count = long(comm.sum(clock_count) / double(scale_factor * numProce)); csv << clock_count << "\t"; } -- GitLab