All Classes Namespaces Functions Variables Typedefs Enumerations Enumerator
Profiler.cpp
00001 /*********************************************************************
00002 * Software License Agreement (BSD License)
00003 *
00004 *  Copyright (c) 2008, Willow Garage, Inc.
00005 *  All rights reserved.
00006 *
00007 *  Redistribution and use in source and binary forms, with or without
00008 *  modification, are permitted provided that the following conditions
00009 *  are met:
00010 *
00011 *   * Redistributions of source code must retain the above copyright
00012 *     notice, this list of conditions and the following disclaimer.
00013 *   * Redistributions in binary form must reproduce the above
00014 *     copyright notice, this list of conditions and the following
00015 *     disclaimer in the documentation and/or other materials provided
00016 *     with the distribution.
00017 *   * Neither the name of the Willow Garage nor the names of its
00018 *     contributors may be used to endorse or promote products derived
00019 *     from this software without specific prior written permission.
00020 *
00021 *  THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
00022 *  "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
00023 *  LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS
00024 *  FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE
00025 *  COPYRIGHT OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT,
00026 *  INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING,
00027 *  BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
00028 *  LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER
00029 *  CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
00030 *  LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN
00031 *  ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
00032 *  POSSIBILITY OF SUCH DAMAGE.
00033 *********************************************************************/
00034 
00035 
00038 #include "ompl/tools/debug/Profiler.h"
00039 
00040 ompl::tools::Profiler& ompl::tools::Profiler::Instance(void)
00041 {
00042     static Profiler p(true, false);
00043     return p;
00044 }
00045 
00046 #if ENABLE_PROFILING
00047 
00048 #include "ompl/util/Console.h"
00049 #include <vector>
00050 #include <algorithm>
00051 #include <sstream>
00052 
00053 void ompl::tools::Profiler::start(void)
00054 {
00055     lock_.lock();
00056     if (!running_)
00057     {
00058         tinfo_.set();
00059         running_ = true;
00060     }
00061     lock_.unlock();
00062 }
00063 
00064 void ompl::tools::Profiler::stop(void)
00065 {
00066     lock_.lock();
00067     if (running_)
00068     {
00069         tinfo_.update();
00070         running_ = false;
00071     }
00072     lock_.unlock();
00073 }
00074 
00075 void ompl::tools::Profiler::clear(void)
00076 {
00077     lock_.lock();
00078     data_.clear();
00079     tinfo_ = TimeInfo();
00080     if (running_)
00081         tinfo_.set();
00082     lock_.unlock();
00083 }
00084 
00085 void ompl::tools::Profiler::event(const std::string &name, const unsigned int times)
00086 {
00087     lock_.lock();
00088     data_[boost::this_thread::get_id()].events[name] += times;
00089     lock_.unlock();
00090 }
00091 
00092 void ompl::tools::Profiler::average(const std::string &name, const double value)
00093 {
00094     lock_.lock();
00095     AvgInfo &a = data_[boost::this_thread::get_id()].avg[name];
00096     a.total += value;
00097     a.totalSqr += value*value;
00098     a.parts++;
00099     lock_.unlock();
00100 }
00101 
00102 void ompl::tools::Profiler::begin(const std::string &name)
00103 {
00104     lock_.lock();
00105     data_[boost::this_thread::get_id()].time[name].set();
00106     lock_.unlock();
00107 }
00108 
00109 void ompl::tools::Profiler::end(const std::string &name)
00110 {
00111     lock_.lock();
00112     data_[boost::this_thread::get_id()].time[name].update();
00113     lock_.unlock();
00114 }
00115 
00116 void ompl::tools::Profiler::status(std::ostream &out, bool merge)
00117 {
00118     stop();
00119     lock_.lock();
00120     printOnDestroy_ = false;
00121 
00122     out << std::endl;
00123     out << " *** Profiling statistics. Total counted time : " << time::seconds(tinfo_.total) << " seconds" << std::endl;
00124 
00125     if (merge)
00126     {
00127         PerThread combined;
00128         for (std::map<boost::thread::id, PerThread>::const_iterator it = data_.begin() ; it != data_.end() ; ++it)
00129         {
00130             for (std::map<std::string, unsigned long int>::const_iterator iev = it->second.events.begin() ; iev != it->second.events.end(); ++iev)
00131                 combined.events[iev->first] += iev->second;
00132             for (std::map<std::string, AvgInfo>::const_iterator iavg = it->second.avg.begin() ; iavg != it->second.avg.end(); ++iavg)
00133             {
00134                 combined.avg[iavg->first].total += iavg->second.total;
00135                 combined.avg[iavg->first].totalSqr += iavg->second.totalSqr;
00136                 combined.avg[iavg->first].parts += iavg->second.parts;
00137             }
00138             for (std::map<std::string, TimeInfo>::const_iterator itm = it->second.time.begin() ; itm != it->second.time.end(); ++itm)
00139             {
00140                 TimeInfo &tc = combined.time[itm->first];
00141                 tc.total = tc.total + itm->second.total;
00142                 tc.parts = tc.parts + itm->second.parts;
00143                 if (tc.shortest > itm->second.shortest)
00144                     tc.shortest = itm->second.shortest;
00145                 if (tc.longest < itm->second.longest)
00146                     tc.longest = itm->second.longest;
00147             }
00148         }
00149         printThreadInfo(out, combined);
00150     }
00151     else
00152         for (std::map<boost::thread::id, PerThread>::const_iterator it = data_.begin() ; it != data_.end() ; ++it)
00153         {
00154             out << "Thread " << it->first << ":" << std::endl;
00155             printThreadInfo(out, it->second);
00156         }
00157     lock_.unlock();
00158 }
00159 
00160 void ompl::tools::Profiler::console(void)
00161 {
00162     static msg::Interface msg("Profiler");
00163 
00164     std::stringstream ss;
00165     ss << std::endl;
00166     status(ss, true);
00167     msg.inform(ss.str());
00168 }
00169 
00171 namespace ompl
00172 {
00173 
00174     struct dataIntVal
00175     {
00176         std::string       name;
00177         unsigned long int value;
00178     };
00179 
00180     struct SortIntByValue
00181     {
00182         bool operator()(const dataIntVal &a, const dataIntVal &b) const
00183         {
00184             return a.value > b.value;
00185         }
00186     };
00187 
00188     struct dataDoubleVal
00189     {
00190         std::string  name;
00191         double       value;
00192     };
00193 
00194     struct SortDoubleByValue
00195     {
00196         bool operator()(const dataDoubleVal &a, const dataDoubleVal &b) const
00197         {
00198             return a.value > b.value;
00199         }
00200     };
00201 }
00203 
00204 void ompl::tools::Profiler::printThreadInfo(std::ostream &out, const PerThread &data)
00205 {
00206     double total = time::seconds(tinfo_.total);
00207 
00208     std::vector<dataIntVal> events;
00209     for (std::map<std::string, unsigned long int>::const_iterator iev = data.events.begin() ; iev != data.events.end() ; ++iev)
00210     {
00211         dataIntVal next = {iev->first, iev->second};
00212         events.push_back(next);
00213     }
00214     std::sort(events.begin(), events.end(), SortIntByValue());
00215     if (!events.empty())
00216         out << "Events:" << std::endl;
00217     for (unsigned int i = 0 ; i < events.size() ; ++i)
00218         out << events[i].name << ": " << events[i].value << std::endl;
00219 
00220     std::vector<dataDoubleVal> avg;
00221     for (std::map<std::string, AvgInfo>::const_iterator ia = data.avg.begin() ; ia != data.avg.end() ; ++ia)
00222     {
00223         dataDoubleVal next = {ia->first, ia->second.total / (double)ia->second.parts};
00224         avg.push_back(next);
00225     }
00226     std::sort(avg.begin(), avg.end(), SortDoubleByValue());
00227     if (!avg.empty())
00228         out << "Averages:" << std::endl;
00229     for (unsigned int i = 0 ; i < avg.size() ; ++i)
00230     {
00231         const AvgInfo &a = data.avg.find(avg[i].name)->second;
00232         out << avg[i].name << ": " << avg[i].value << " (stddev = " <<
00233           sqrt(fabs(a.totalSqr - (double)a.parts * avg[i].value * avg[i].value) / ((double)a.parts - 1.)) << ")" << std::endl;
00234     }
00235 
00236     std::vector<dataDoubleVal> time;
00237 
00238     for (std::map<std::string, TimeInfo>::const_iterator itm = data.time.begin() ; itm != data.time.end() ; ++itm)
00239     {
00240         dataDoubleVal next = {itm->first, time::seconds(itm->second.total)};
00241         time.push_back(next);
00242     }
00243 
00244     std::sort(time.begin(), time.end(), SortDoubleByValue());
00245     if (!time.empty())
00246         out << "Blocks of time:" << std::endl;
00247 
00248     double unaccounted = total;
00249     for (unsigned int i = 0 ; i < time.size() ; ++i)
00250     {
00251         const TimeInfo &d = data.time.find(time[i].name)->second;
00252 
00253         double tS = time::seconds(d.shortest);
00254         double tL = time::seconds(d.longest);
00255         out << time[i].name << ": " << time[i].value << "s (" << (100.0 * time[i].value/total) << "%), ["
00256             << tS << "s --> " << tL << " s], " << d.parts << " parts";
00257         if (d.parts > 0)
00258             out << ", " << (time::seconds(d.total) / (double)d.parts) << " s on average";
00259         out << std::endl;
00260         unaccounted -= time[i].value;
00261     }
00262     out << "Unaccounted time : " << unaccounted;
00263     if (total > 0.0)
00264         out << " (" << (100.0 * unaccounted / total) << " %)";
00265     out << std::endl;
00266 
00267     out << std::endl;
00268 }
00269 
00270 #endif
 All Classes Namespaces Functions Variables Typedefs Enumerations Enumerator Friends