PLearn 0.1
Profiler.cc
Go to the documentation of this file.
00001 // -*- C++ -*-
00002 
00003 // PLearn (A C++ Machine Learning Library)
00004 // Copyright (C) 2001 Yoshua Bengio and University of Montreal
00005 //
00006 
00007 // Redistribution and use in source and binary forms, with or without
00008 // modification, are permitted provided that the following conditions are met:
00009 // 
00010 //  1. Redistributions of source code must retain the above copyright
00011 //     notice, this list of conditions and the following disclaimer.
00012 // 
00013 //  2. Redistributions in binary form must reproduce the above copyright
00014 //     notice, this list of conditions and the following disclaimer in the
00015 //     documentation and/or other materials provided with the distribution.
00016 // 
00017 //  3. The name of the authors may not be used to endorse or promote
00018 //     products derived from this software without specific prior written
00019 //     permission.
00020 // 
00021 // THIS SOFTWARE IS PROVIDED BY THE AUTHORS ``AS IS'' AND ANY EXPRESS OR
00022 // IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
00023 // OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN
00024 // NO EVENT SHALL THE AUTHORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
00025 // SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED
00026 // TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
00027 // PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
00028 // LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
00029 // NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
00030 // SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
00031 // 
00032 // This file is part of the PLearn library. For more information on the PLearn
00033 // library, go to the PLearn Web site at www.plearn.org
00034 
00035 /* *******************************************************      
00036  * $Id: Profiler.cc 9591 2008-10-21 16:20:53Z nouiz $
00037  * This file is part of the PLearn library.
00038  ******************************************************* */
00039 
00040 #include "Profiler.h"
00041 #include <time.h>
00042 
00043 #ifdef _OPENMP
00044 #include<omp.h>
00045 #include<plearn/base/tostring.h>
00046 #endif
00047 
00048 namespace PLearn {
00049 using namespace std;
00050 
00051 // initialize static variables
00052 map<string,Profiler::Stats> Profiler::codes_statistics;
00053 #ifdef PROFILE
00054 struct tms Profiler::t;
00055 #endif
00056 bool Profiler::active  = false;
00057 
00058 
00059 string Profiler::get_omp_save_name(const string name_of_piece_of_code){
00060 #ifdef _OPENMP
00061     return name_of_piece_of_code+tostring(omp_get_thread_num());
00062 #else
00063     return name_of_piece_of_code;
00064 #endif
00065 }
00066 
00067 #ifdef PROFILE
00068 // start recording time for named piece of code
00069 void Profiler::start(const string& name_of_piece_of_code_, const int max_nb_going)
00070 {
00071     string name_of_piece_of_code=get_omp_save_name(name_of_piece_of_code_);
00072 #ifdef _OPENMP
00073 #pragma omp critical (codes_statistics)
00074 #endif
00075     if (active)
00076     {
00077         map<string,Profiler::Stats>::iterator it = 
00078             codes_statistics.find(name_of_piece_of_code);
00079         if (it == codes_statistics.end())
00080         {
00081             Stats stats;
00082             stats.nb_going = 1;
00083             stats.wall_last_start   = times(&t);
00084             stats.user_last_start   = t.tms_utime;
00085             stats.system_last_start = t.tms_stime;
00086             codes_statistics[name_of_piece_of_code] = stats;
00087         }
00088         else
00089         {
00090             Profiler::Stats& stats = it->second;
00091             if (stats.nb_going >= max_nb_going)
00092                 PLERROR("Profiler::start(%s) called while previous %d starts had not ended and we allowed only %d starts",
00093                         name_of_piece_of_code.c_str(),stats.nb_going, max_nb_going);
00094             if (stats.nb_going==0){
00095                 stats.wall_last_start   = times(&t);
00096                 stats.user_last_start   = t.tms_utime;
00097                 stats.system_last_start = t.tms_stime;
00098             }
00099             stats.nb_going++;
00100         }
00101     }
00102 }
00103 
00104   
00105 // end recording time for named piece of code, and increment
00106 // frequency of occurence and total duration of this piece of code.
00107 void Profiler::end(const string& name_of_piece_of_code_)
00108 {
00109     string name_of_piece_of_code=get_omp_save_name(name_of_piece_of_code_);
00110 #ifdef _OPENMP
00111 #pragma omp critical (codes_statistics)
00112 #endif
00113     if (active)
00114     {
00115         clock_t end_time = times(&t);
00116         map<string,Profiler::Stats>::iterator it = 
00117             codes_statistics.find(name_of_piece_of_code);
00118         if (it == codes_statistics.end())
00119             PLERROR("Profiler::end(%s) called before any call to start(%s)",
00120                     name_of_piece_of_code.c_str(),name_of_piece_of_code.c_str());
00121         Profiler::Stats& stats = it->second;
00122         if (stats.nb_going == 0)
00123             PLERROR("Profiler::end(%s) called before previous start was called",
00124                     name_of_piece_of_code.c_str());
00125 
00126         stats.nb_going--;
00127         stats.frequency_of_occurence++;
00128         if (stats.nb_going==0){
00129             long wall_duration   = end_time    - stats.wall_last_start;
00130             long user_duration   = t.tms_utime - stats.user_last_start;
00131             long system_duration = t.tms_stime - stats.system_last_start;
00132             stats.wall_duration   += wall_duration;
00133             stats.user_duration   += user_duration;
00134             stats.system_duration += system_duration;
00135             if (wall_duration < 0) {
00136                 wall_duration = user_duration = system_duration = 1;
00137                 PLWARNING("Profiler: negative duration measured with times!");
00138             }
00139         }
00140     }
00141 }
00142 
00143 #ifdef PL_PROFILE
00144 // call Profiler::start if PL_PROFILE is set
00145 void Profiler::pl_profile_start(const string& name_of_piece_of_code, const int max_nb_going){
00146     Profiler::start(name_of_piece_of_code, max_nb_going);}
00147 // call Profiler::end if PL_PROFILE is set
00148 void Profiler::pl_profile_end(const string& name_of_piece_of_code){
00149     Profiler::end(name_of_piece_of_code);}
00150 // call Profiler::activate if PL_PROFILE is set
00151 void Profiler::pl_profile_activate(){
00152     Profiler::activate();}
00153 // call Profiler::deactivate if PL_PROFILE is set
00154 void Profiler::pl_profile_deactivate(){
00155     Profiler::deactivate();}
00156 // call Profiler::report if PL_PROFILE is set
00157 void Profiler::pl_profile_report(ostream& out){
00158     Profiler::report(out);}
00159 void Profiler::pl_profile_report(PStream out){
00160     Profiler::report(out);}
00161 // call Profiler::reportwall if PL_PROFILE is set
00162 void Profiler::pl_profile_reportwall(ostream& out){
00163     Profiler::reportwall(out);}
00164 void Profiler::pl_profile_reportwall(PStream out){
00165     Profiler::reportwall(out);}
00166 #endif
00167 
00168 #endif
00169 
00172 const Profiler::Stats& Profiler::getStats(const string& name_of_piece_of_code_)
00173 {
00174     string name_of_piece_of_code=get_omp_save_name(name_of_piece_of_code_);
00175     Stats* s;
00176 #ifdef _OPENMP
00177 #pragma omp critical (codes_statistics)
00178 #endif
00179 {
00180     map<string,Stats>::iterator it = codes_statistics.find(name_of_piece_of_code);
00181     if (it == codes_statistics.end())
00182         PLERROR("Profiler::getStats: cannot find statistics for '%s'. the active variable is at: %d",
00183                 name_of_piece_of_code.c_str(),active);
00184     s = &(it->second);
00185 }
00186 return *s;
00187 }
00188 
00189 
00192 void Profiler::reset(const string& name_of_piece_of_code_)
00193 {
00194     string name_of_piece_of_code=get_omp_save_name(name_of_piece_of_code_);
00195 
00196     Stats empty;
00197 #ifdef _OPENMP
00198 #pragma omp critical (codes_statistics)
00199 #endif
00200     codes_statistics[name_of_piece_of_code] = empty;
00201 }
00202 
00203 
00204 // output a report on the output stream, giving
00205 // the statistics recorded for each of the named pieces of codes.
00206 void Profiler::report(ostream& out)
00207 {
00208     report(PStream(&out));
00209 }
00210 void Profiler::report(PStream out)
00211 {
00212 #ifdef _OPENMP
00213 #pragma omp critical (codes_statistics)
00214 #endif
00215 {
00216     map<string,Profiler::Stats>::iterator it =  
00217         codes_statistics.begin(), end =  codes_statistics.end();
00218 
00219     out << "*** PLearn::Profiler Report ***" << endl;
00220     out << "Ticks per second : " << ticksPerSecond() <<endl;
00221     for ( ; it!=end ; ++it)
00222     {
00223         out << endl << "For " << it->first << " :" << endl;
00224         Profiler::Stats& stats = it->second;
00225         out << "Frequency of occurence   = " << stats.frequency_of_occurence << endl;
00226         out << "Wall duration   (ticks)  = " << stats.wall_duration << endl
00227             << "User duration   (ticks)  = " << stats.user_duration << endl
00228             << "System duration (ticks)  = " << stats.system_duration << endl;
00229 
00230         double avg_wall = (double)stats.wall_duration/stats.frequency_of_occurence;
00231         double avg_user = (double)stats.user_duration/stats.frequency_of_occurence;
00232         double avg_sys  = (double)stats.system_duration/stats.frequency_of_occurence;
00233         out << "Average wall   duration  = " << avg_wall << endl
00234             << "Average user   duration  = " << avg_user << endl
00235             << "Average system duration  = " << avg_sys  << endl;
00236     }
00237 }
00238 }
00239 
00240 // output a report on the output stream, giving
00241 // the wall time statistics recorded for each of the named pieces of code
00242 void Profiler::reportwall(ostream& out)
00243 {
00244     reportwall(PStream(&out));
00245 }
00246 void Profiler::reportwall(PStream out)
00247 {
00248 #ifdef _OPENMP
00249 #pragma omp critical (codes_statistics)
00250 #endif
00251 {
00252     map<string,Profiler::Stats>::iterator it =  
00253         codes_statistics.begin(), end =  codes_statistics.end();
00254 
00255     out << "*** PLearn::Profiler Wall Report ***" << endl;
00256     out << "Ticks per second : " << ticksPerSecond() <<endl;
00257     for ( ; it!=end ; ++it)
00258     {
00259         out << endl << "For " << it->first << " :" << endl;
00260         Profiler::Stats& stats = it->second;
00261         out << "Frequency of occurence   = " << stats.frequency_of_occurence << endl;
00262         out << "Wall duration   (ticks)  = " << stats.wall_duration << endl;
00263 
00264         double avg_wall = (double)stats.wall_duration/stats.frequency_of_occurence;
00265         out << "Average wall   duration  = " << avg_wall << endl;
00266     }
00267 }
00268 }
00269 
00270 } // end of namespace PLearn
00271 
00272 
00273 /*
00274   Local Variables:
00275   mode:c++
00276   c-basic-offset:4
00277   c-file-style:"stroustrup"
00278   c-file-offsets:((innamespace . 0)(inline-open . 0))
00279   indent-tabs-mode:nil
00280   fill-column:79
00281   End:
00282 */
00283 // vim: filetype=cpp:expandtab:shiftwidth=4:tabstop=8:softtabstop=4:encoding=utf-8:textwidth=79 :
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Defines