00001
00002
00003
00004
00005
00006
00007
00008
00009
00010
00011
00012
00013
00014
00015
00016
00017
00018
00019
00020
00021
00022
00023
00024
00025
00026
00027
00028
00029
00030
00031
00032
00033
00034
00035
00038 #include "ompl/util/Profiler.h"
00039
00040 ompl::Profiler* ompl::Profiler::Instance(void)
00041 {
00042 static Profiler p(true, true);
00043 return &p;
00044 }
00045
00046 #if ENABLE_PROFILING
00047
00048 #include <vector>
00049 #include <algorithm>
00050
00051 void ompl::Profiler::start(void)
00052 {
00053 lock_.lock();
00054 if (!running_)
00055 {
00056 tinfo_.set();
00057 running_ = true;
00058 }
00059 lock_.unlock();
00060 }
00061
00062 void ompl::Profiler::stop(void)
00063 {
00064 lock_.lock();
00065 if (running_)
00066 {
00067 tinfo_.update();
00068 running_ = false;
00069 }
00070 lock_.unlock();
00071 }
00072
00073 void ompl::Profiler::clear(void)
00074 {
00075 lock_.lock();
00076 data_.clear();
00077 tinfo_ = TimeInfo();
00078 if (running_)
00079 tinfo_.set();
00080 lock_.unlock();
00081 }
00082
00083 void ompl::Profiler::event(const std::string &name, const unsigned int times)
00084 {
00085 lock_.lock();
00086 data_[boost::this_thread::get_id()].events[name] += times;
00087 lock_.unlock();
00088 }
00089
00090 void ompl::Profiler::begin(const std::string &name)
00091 {
00092 lock_.lock();
00093 data_[boost::this_thread::get_id()].time[name].set();
00094 lock_.unlock();
00095 }
00096
00097 void ompl::Profiler::end(const std::string &name)
00098 {
00099 lock_.lock();
00100 data_[boost::this_thread::get_id()].time[name].update();
00101 lock_.unlock();
00102 }
00103
00104 void ompl::Profiler::status(std::ostream &out, bool merge)
00105 {
00106 stop();
00107 lock_.lock();
00108 printOnDestroy_ = false;
00109
00110 out << std::endl;
00111 out << " *** Profiling statistics. Total counted time : " << time::seconds(tinfo_.total) << " seconds" << std::endl;
00112
00113 if (merge)
00114 {
00115 PerThread combined;
00116 for (std::map<boost::thread::id, PerThread>::const_iterator it = data_.begin() ; it != data_.end() ; ++it)
00117 {
00118 for (std::map<std::string, unsigned long int>::const_iterator iev = it->second.events.begin() ; iev != it->second.events.end(); ++iev)
00119 combined.events[iev->first] += iev->second;
00120 for (std::map<std::string, TimeInfo>::const_iterator itm = it->second.time.begin() ; itm != it->second.time.end(); ++itm)
00121 {
00122 TimeInfo &tc = combined.time[itm->first];
00123 tc.total = tc.total + itm->second.total;
00124 tc.parts = tc.parts + itm->second.parts;
00125 if (tc.shortest > itm->second.shortest)
00126 tc.shortest = itm->second.shortest;
00127 if (tc.longest < itm->second.longest)
00128 tc.longest = itm->second.longest;
00129 }
00130 }
00131 printThreadInfo(out, combined);
00132 }
00133 else
00134 for (std::map<boost::thread::id, PerThread>::const_iterator it = data_.begin() ; it != data_.end() ; ++it)
00135 {
00136 out << "Thread " << it->first << ":" << std::endl;
00137 printThreadInfo(out, it->second);
00138 }
00139 lock_.unlock();
00140 }
00141
00142 namespace ompl
00143 {
00144
00145 struct dEnv
00146 {
00147 std::string name;
00148 unsigned long int value;
00149 };
00150
00151 struct SortEnvByValue
00152 {
00153 bool operator()(const dEnv &a, const dEnv &b) const
00154 {
00155 return a.value > b.value;
00156 }
00157 };
00158
00159 struct dTm
00160 {
00161 std::string name;
00162 double value;
00163 };
00164
00165 struct SortTmByValue
00166 {
00167 bool operator()(const dTm &a, const dTm &b) const
00168 {
00169 return a.value > b.value;
00170 }
00171 };
00172 }
00173
00174 void ompl::Profiler::printThreadInfo(std::ostream &out, const PerThread &data)
00175 {
00176 double total = time::seconds(tinfo_.total);
00177
00178 std::vector<dEnv> events;
00179
00180 for (std::map<std::string, unsigned long int>::const_iterator iev = data.events.begin() ; iev != data.events.end() ; ++iev)
00181 {
00182 dEnv next = {iev->first, iev->second};
00183 events.push_back(next);
00184 }
00185
00186 std::sort(events.begin(), events.end(), SortEnvByValue());
00187
00188 for (unsigned int i = 0 ; i < events.size() ; ++i)
00189 out << events[i].name << ": " << events[i].value << std::endl;
00190
00191 std::vector<dTm> time;
00192
00193 for (std::map<std::string, TimeInfo>::const_iterator itm = data.time.begin() ; itm != data.time.end() ; ++itm)
00194 {
00195 dTm next = {itm->first, time::seconds(itm->second.total)};
00196 time.push_back(next);
00197 }
00198
00199 std::sort(time.begin(), time.end(), SortTmByValue());
00200
00201 double unaccounted = total;
00202 for (unsigned int i = 0 ; i < time.size() ; ++i)
00203 {
00204 const TimeInfo &d = data.time.find(time[i].name)->second;
00205
00206 double tS = time::seconds(d.shortest);
00207 double tL = time::seconds(d.longest);
00208 out << time[i].name << ": " << time[i].value << "s (" << (100.0 * time[i].value/total) << "%), ["
00209 << tS << "s --> " << tL << " s], " << d.parts << " parts" << std::endl;
00210 unaccounted -= time[i].value;
00211 }
00212 out << "Unaccounted time : " << unaccounted << " (" << (100.0 * unaccounted / total) << " %)" << std::endl;
00213
00214 out << std::endl;
00215 }
00216
00217 #endif