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/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 "ompl/util/Console.h"
00049 #include <vector>
00050 #include <algorithm>
00051 #include <sstream>
00052 
00053 void ompl::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::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::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::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::Profiler::begin(const std::string &name)
00093 {
00094     lock_.lock();
00095     data_[boost::this_thread::get_id()].time[name].set();
00096     lock_.unlock();
00097 }
00098 
00099 void ompl::Profiler::end(const std::string &name)
00100 {
00101     lock_.lock();
00102     data_[boost::this_thread::get_id()].time[name].update();
00103     lock_.unlock();
00104 }
00105 
00106 void ompl::Profiler::status(std::ostream &out, bool merge)
00107 {
00108     stop();
00109     lock_.lock();
00110     printOnDestroy_ = false;
00111 
00112     out << std::endl;
00113     out << " *** Profiling statistics. Total counted time : " << time::seconds(tinfo_.total) << " seconds" << std::endl;
00114 
00115     if (merge)
00116     {
00117         PerThread combined;
00118         for (std::map<boost::thread::id, PerThread>::const_iterator it = data_.begin() ; it != data_.end() ; ++it)
00119         {
00120             for (std::map<std::string, unsigned long int>::const_iterator iev = it->second.events.begin() ; iev != it->second.events.end(); ++iev)
00121                 combined.events[iev->first] += iev->second;
00122             for (std::map<std::string, TimeInfo>::const_iterator itm = it->second.time.begin() ; itm != it->second.time.end(); ++itm)
00123             {
00124                 TimeInfo &tc = combined.time[itm->first];
00125                 tc.total = tc.total + itm->second.total;
00126                 tc.parts = tc.parts + itm->second.parts;
00127                 if (tc.shortest > itm->second.shortest)
00128                     tc.shortest = itm->second.shortest;
00129                 if (tc.longest < itm->second.longest)
00130                     tc.longest = itm->second.longest;
00131             }
00132         }
00133         printThreadInfo(out, combined);
00134     }
00135     else
00136         for (std::map<boost::thread::id, PerThread>::const_iterator it = data_.begin() ; it != data_.end() ; ++it)
00137         {
00138             out << "Thread " << it->first << ":" << std::endl;
00139             printThreadInfo(out, it->second);
00140         }
00141     lock_.unlock();
00142 }
00143 
00144 void ompl::Profiler::console(void)
00145 {
00146     static msg::Interface msg("Profiler");
00147 
00148     std::stringstream ss;
00149     ss << std::endl;
00150     status(ss, true);
00151     msg.inform(ss.str());
00152 }
00153 
00154 namespace ompl
00155 {
00156 
00157     struct dEnv
00158     {
00159         std::string       name;
00160         unsigned long int value;
00161     };
00162 
00163     struct SortEnvByValue
00164     {
00165         bool operator()(const dEnv &a, const dEnv &b) const
00166         {
00167             return a.value > b.value;
00168         }
00169     };
00170 
00171     struct dTm
00172     {
00173         std::string  name;
00174         double       value;
00175     };
00176 
00177     struct SortTmByValue
00178     {
00179         bool operator()(const dTm &a, const dTm &b) const
00180         {
00181             return a.value > b.value;
00182         }
00183     };
00184 }
00185 
00186 void ompl::Profiler::printThreadInfo(std::ostream &out, const PerThread &data)
00187 {
00188     double total = time::seconds(tinfo_.total);
00189 
00190     std::vector<dEnv> events;
00191 
00192     for (std::map<std::string, unsigned long int>::const_iterator iev = data.events.begin() ; iev != data.events.end() ; ++iev)
00193     {
00194         dEnv next = {iev->first, iev->second};
00195         events.push_back(next);
00196     }
00197 
00198     std::sort(events.begin(), events.end(), SortEnvByValue());
00199 
00200     for (unsigned int i = 0 ; i < events.size() ; ++i)
00201         out << events[i].name << ": " << events[i].value << std::endl;
00202 
00203     std::vector<dTm> time;
00204 
00205     for (std::map<std::string, TimeInfo>::const_iterator itm = data.time.begin() ; itm != data.time.end() ; ++itm)
00206     {
00207         dTm next = {itm->first, time::seconds(itm->second.total)};
00208         time.push_back(next);
00209     }
00210 
00211     std::sort(time.begin(), time.end(), SortTmByValue());
00212 
00213     double unaccounted = total;
00214     for (unsigned int i = 0 ; i < time.size() ; ++i)
00215     {
00216         const TimeInfo &d = data.time.find(time[i].name)->second;
00217 
00218         double tS = time::seconds(d.shortest);
00219         double tL = time::seconds(d.longest);
00220         out << time[i].name << ": " << time[i].value << "s (" << (100.0 * time[i].value/total) << "%), ["
00221             << tS << "s --> " << tL << " s], " << d.parts << " parts";
00222         if (d.parts > 0)
00223             out << ", " << (time::seconds(d.total) / (double)d.parts) << " s on average";
00224         out << std::endl;
00225         unaccounted -= time[i].value;
00226     }
00227     out << "Unaccounted time : " << unaccounted;
00228     if (total > 0.0)
00229         out << " (" << (100.0 * unaccounted / total) << " %)";
00230     out << std::endl;
00231 
00232     out << std::endl;
00233 }
00234 
00235 #endif