lbajardsilogic@0: /* -*- c-basic-offset: 4 indent-tabs-mode: nil -*-  vi:set ts=8 sts=4 sw=4: */
lbajardsilogic@0: 
lbajardsilogic@0: /*
lbajardsilogic@0:     Sonic Visualiser
lbajardsilogic@0:     An audio file viewer and annotation editor.
lbajardsilogic@0:     Centre for Digital Music, Queen Mary, University of London.
lbajardsilogic@0:     
lbajardsilogic@0:     This program is free software; you can redistribute it and/or
lbajardsilogic@0:     modify it under the terms of the GNU General Public License as
lbajardsilogic@0:     published by the Free Software Foundation; either version 2 of the
lbajardsilogic@0:     License, or (at your option) any later version.  See the file
lbajardsilogic@0:     COPYING included with this distribution for more information.
lbajardsilogic@0: */
lbajardsilogic@0: 
lbajardsilogic@0: /*
lbajardsilogic@0:    This is a modified version of a source file from the 
lbajardsilogic@0:    Rosegarden MIDI and audio sequencer and notation editor.
lbajardsilogic@0:    This file copyright 2000-2006 Chris Cannam, Guillaume Laurent,
lbajardsilogic@0:    and QMUL.
lbajardsilogic@0: */
lbajardsilogic@0: 
lbajardsilogic@0: #include <iostream>
lbajardsilogic@0: 
lbajardsilogic@0: #include <vector>
lbajardsilogic@0: #include <algorithm>
lbajardsilogic@0: #include <set>
lbajardsilogic@0: #include <map>
lbajardsilogic@0: 
lbarthelemy@187: #include "Profiler.h"
lbarthelemy@187: 
lbarthelemy@187: 
lbajardsilogic@0: using std::cerr;
lbajardsilogic@0: using std::endl;
lbajardsilogic@0: 
lbajardsilogic@0: Profiles* Profiles::m_instance = 0;
lbajardsilogic@0: 
lbajardsilogic@0: Profiles* Profiles::getInstance()
lbajardsilogic@0: {
lbajardsilogic@0:     if (!m_instance) m_instance = new Profiles();
lbajardsilogic@0:     
lbajardsilogic@0:     return m_instance;
lbajardsilogic@0: }
lbajardsilogic@0: 
lbajardsilogic@0: Profiles::Profiles()
lbajardsilogic@0: {
lbajardsilogic@0: }
lbajardsilogic@0: 
lbajardsilogic@0: Profiles::~Profiles()
lbajardsilogic@0: {
lbajardsilogic@0:     dump();
lbajardsilogic@0: }
lbajardsilogic@0: 
lbajardsilogic@0: void Profiles::accumulate(
lbajardsilogic@0: #ifndef NO_TIMING
lbajardsilogic@0:     const char* id, clock_t time, RealTime rt
lbajardsilogic@0: #else
lbajardsilogic@0:     const char*, clock_t, RealTime
lbajardsilogic@0: #endif
lbajardsilogic@0: )
lbajardsilogic@0: {
lbajardsilogic@0: #ifndef NO_TIMING    
lbajardsilogic@0:     ProfilePair &pair(m_profiles[id]);
lbajardsilogic@0:     ++pair.first;
lbajardsilogic@0:     pair.second.first += time;
lbajardsilogic@0:     pair.second.second = pair.second.second + rt;
lbajardsilogic@0: 
lbajardsilogic@0:     TimePair &lastPair(m_lastCalls[id]);
lbajardsilogic@0:     lastPair.first = time;
lbajardsilogic@0:     lastPair.second = rt;
lbajardsilogic@0: 
lbajardsilogic@0:     TimePair &worstPair(m_worstCalls[id]);
lbajardsilogic@0:     if (time > worstPair.first) {
lbajardsilogic@0:         worstPair.first = time;
lbajardsilogic@0:     }
lbajardsilogic@0:     if (rt > worstPair.second) {
lbajardsilogic@0:         worstPair.second = rt;
lbajardsilogic@0:     }
lbajardsilogic@0: #endif
lbajardsilogic@0: }
lbajardsilogic@0: 
lbajardsilogic@0: void Profiles::dump() const
lbajardsilogic@0: {
lbajardsilogic@0: #ifndef NO_TIMING
lbajardsilogic@0: 
lbajardsilogic@0:     fprintf(stderr, "Profiling points:\n");
lbajardsilogic@0: 
lbajardsilogic@0:     fprintf(stderr, "\nBy name:\n");
lbajardsilogic@0: 
lbajardsilogic@0:     typedef std::set<const char *, std::less<std::string> > StringSet;
lbajardsilogic@0: 
lbajardsilogic@0:     StringSet profileNames;
lbajardsilogic@0:     for (ProfileMap::const_iterator i = m_profiles.begin();
lbajardsilogic@0:          i != m_profiles.end(); ++i) {
lbajardsilogic@0:         profileNames.insert(i->first);
lbajardsilogic@0:     }
lbajardsilogic@0: 
lbajardsilogic@0:     for (StringSet::const_iterator i = profileNames.begin();
lbajardsilogic@0:          i != profileNames.end(); ++i) {
lbajardsilogic@0: 
lbajardsilogic@0:         ProfileMap::const_iterator j = m_profiles.find(*i);
lbajardsilogic@0: 
lbajardsilogic@0:         if (j == m_profiles.end()) continue;
lbajardsilogic@0: 
lbajardsilogic@0:         const ProfilePair &pp(j->second);
lbajardsilogic@0: 
lbajardsilogic@0:         fprintf(stderr, "%s(%d):\n", *i, pp.first);
lbajardsilogic@0: 
lbajardsilogic@0:         fprintf(stderr, "\tCPU:  \t%.9g ms/call \t[%d ms total]\n",
lbajardsilogic@0:                 (((double)pp.second.first * 1000.0 /
lbajardsilogic@0: 		  (double)pp.first) / CLOCKS_PER_SEC),
lbajardsilogic@0:                 int((pp.second.first * 1000.0) / CLOCKS_PER_SEC));
lbajardsilogic@0: 
lbajardsilogic@0:         fprintf(stderr, "\tReal: \t%s ms      \t[%s ms total]\n",
lbajardsilogic@0:                 ((pp.second.second / pp.first) * 1000).toString().c_str(),
lbajardsilogic@0:                 (pp.second.second * 1000).toString().c_str());
lbajardsilogic@0: 
lbajardsilogic@0:         WorstCallMap::const_iterator k = m_worstCalls.find(*i);
lbajardsilogic@0:         if (k == m_worstCalls.end()) continue;
lbajardsilogic@0:         
lbajardsilogic@0:         const TimePair &wc(k->second);
lbajardsilogic@0: 
lbajardsilogic@0:         fprintf(stderr, "\tWorst:\t%s ms/call \t[%d ms CPU]\n",
lbajardsilogic@0:                 (wc.second * 1000).toString().c_str(),
lbajardsilogic@0:                 int((wc.first * 1000.0) / CLOCKS_PER_SEC));
lbajardsilogic@0:     }
lbajardsilogic@0: 
lbajardsilogic@0:     typedef std::multimap<RealTime, const char *> TimeRMap;
lbajardsilogic@0:     typedef std::multimap<int, const char *> IntRMap;
lbajardsilogic@0:     
lbajardsilogic@0:     TimeRMap totmap, avgmap, worstmap;
lbajardsilogic@0:     IntRMap ncallmap;
lbajardsilogic@0: 
lbajardsilogic@0:     for (ProfileMap::const_iterator i = m_profiles.begin();
lbajardsilogic@0:          i != m_profiles.end(); ++i) {
lbajardsilogic@0:         totmap.insert(TimeRMap::value_type(i->second.second.second, i->first));
lbajardsilogic@0:         avgmap.insert(TimeRMap::value_type(i->second.second.second /
lbajardsilogic@0:                                            i->second.first, i->first));
lbajardsilogic@0:         ncallmap.insert(IntRMap::value_type(i->second.first, i->first));
lbajardsilogic@0:     }
lbajardsilogic@0: 
lbajardsilogic@0:     for (WorstCallMap::const_iterator i = m_worstCalls.begin();
lbajardsilogic@0:          i != m_worstCalls.end(); ++i) {
lbajardsilogic@0:         worstmap.insert(TimeRMap::value_type(i->second.second,
lbajardsilogic@0:                                              i->first));
lbajardsilogic@0:     }
lbajardsilogic@0: 
lbajardsilogic@0: 
lbajardsilogic@0:     fprintf(stderr, "\nBy total:\n");
lbajardsilogic@0:     for (TimeRMap::const_iterator i = totmap.end(); i != totmap.begin(); ) {
lbajardsilogic@0:         --i;
lbajardsilogic@0:         fprintf(stderr, "%-40s  %s ms\n", i->second,
lbajardsilogic@0:                 (i->first * 1000).toString().c_str());
lbajardsilogic@0:     }
lbajardsilogic@0: 
lbajardsilogic@0:     fprintf(stderr, "\nBy average:\n");
lbajardsilogic@0:     for (TimeRMap::const_iterator i = avgmap.end(); i != avgmap.begin(); ) {
lbajardsilogic@0:         --i;
lbajardsilogic@0:         fprintf(stderr, "%-40s  %s ms\n", i->second,
lbajardsilogic@0:                 (i->first * 1000).toString().c_str());
lbajardsilogic@0:     }
lbajardsilogic@0: 
lbajardsilogic@0:     fprintf(stderr, "\nBy worst case:\n");
lbajardsilogic@0:     for (TimeRMap::const_iterator i = worstmap.end(); i != worstmap.begin(); ) {
lbajardsilogic@0:         --i;
lbajardsilogic@0:         fprintf(stderr, "%-40s  %s ms\n", i->second,
lbajardsilogic@0:                 (i->first * 1000).toString().c_str(), i->second);
lbajardsilogic@0:     }
lbajardsilogic@0: 
lbajardsilogic@0:     fprintf(stderr, "\nBy number of calls:\n");
lbajardsilogic@0:     for (IntRMap::const_iterator i = ncallmap.end(); i != ncallmap.begin(); ) {
lbajardsilogic@0:         --i;
lbajardsilogic@0:         fprintf(stderr, "%-40s  %d\n", i->second, i->first);
lbajardsilogic@0:     }
lbajardsilogic@0: 
lbajardsilogic@0: #endif
lbajardsilogic@0: }
lbajardsilogic@0: 
lbajardsilogic@0: #ifndef NO_TIMING    
lbajardsilogic@0: 
lbajardsilogic@0: Profiler::Profiler(const char* c, bool showOnDestruct)
lbajardsilogic@0:     : m_c(c),
lbajardsilogic@0:       m_showOnDestruct(showOnDestruct)
lbajardsilogic@0: {
lbajardsilogic@0:     m_startCPU = clock();
lbajardsilogic@0: 
lbajardsilogic@0:     struct timeval tv;
lbajardsilogic@0:     (void)gettimeofday(&tv, 0);
lbajardsilogic@0:     m_startTime = RealTime::fromTimeval(tv);
lbajardsilogic@0: }
lbajardsilogic@0: 
lbajardsilogic@0: void
lbajardsilogic@0: Profiler::update() const
lbajardsilogic@0: {
lbajardsilogic@0:     clock_t elapsedCPU = clock() - m_startCPU;
lbajardsilogic@0: 
lbajardsilogic@0:     struct timeval tv;
lbajardsilogic@0:     (void)gettimeofday(&tv, 0);
lbajardsilogic@0:     RealTime elapsedTime = RealTime::fromTimeval(tv) - m_startTime;
lbajardsilogic@0: 
lbajardsilogic@0:     cerr << "Profiler : id = " << m_c
lbajardsilogic@0: 	 << " - elapsed so far = " << ((elapsedCPU * 1000) / CLOCKS_PER_SEC)
lbajardsilogic@0: 	 << "ms CPU, " << elapsedTime << " real" << endl;
lbajardsilogic@0: }    
lbajardsilogic@0: 
lbajardsilogic@0: Profiler::~Profiler()
lbajardsilogic@0: {
lbajardsilogic@0:     clock_t elapsedCPU = clock() - m_startCPU;
lbajardsilogic@0: 
lbajardsilogic@0:     struct timeval tv;
lbajardsilogic@0:     (void)gettimeofday(&tv, 0);
lbajardsilogic@0:     RealTime elapsedTime = RealTime::fromTimeval(tv) - m_startTime;
lbajardsilogic@0: 
lbajardsilogic@0:     Profiles::getInstance()->accumulate(m_c, elapsedCPU, elapsedTime);
lbajardsilogic@0: 
lbajardsilogic@0:     if (m_showOnDestruct)
lbajardsilogic@0:         cerr << "Profiler : id = " << m_c
lbajardsilogic@0:              << " - elapsed = " << ((elapsedCPU * 1000) / CLOCKS_PER_SEC)
lbajardsilogic@0: 	     << "ms CPU, " << elapsedTime << " real" << endl;
lbajardsilogic@0: }
lbajardsilogic@0:  
lbajardsilogic@0: #endif
lbajardsilogic@0: