artvertiser/FProfiler/FProfiler.cpp

   1 /*
   2  *  FProfiler.cpp
   3  *  F
   4  *
   5  *  Created by damian on 25/5/08.
   6  *  Copyright 2008 frey damian@frey.co.nz. All rights reserved.
   7  *
   8  */
   9
  10 #include "FProfiler.h"
  11
  12 #include <algorithm>
  13
  14 #include "FThread.h"
  15
  16 FProfiler::FProfileContexts FProfiler::contexts;
  17 FSemaphore FProfiler::lock;
  18
  19 int FProfileSection::EXEC_ORDER_ID = 0;
  20
  21 FTime FProfiler::end_time;
  22
  23 FProfileContext::~FProfileContext()
  24 {
  25     if ( toplevel )
  26         delete toplevel;
  27 }
  28
  29 FProfileContext* FProfiler::GetContext()
  30 {
  31         FThreadContext thread_context;
  32         lock.Wait();
  33         // try to get current thread context
  34         for ( FProfileContexts::const_iterator i = contexts.begin();
  35                   i!= contexts.end();
  36                   ++i )
  37         {
  38                 if ( thread_context == ( *i )->thread_context )
  39                 {
  40                         lock.Signal();
  41                         return *i;
  42                 }
  43         }
  44
  45         // no context found for this thread: must create a new one
  46         FProfileContext* context = new FProfileContext();
  47         // add it to the vector
  48         contexts.push_back( context );
  49         // fill in details
  50         context->thread_context.Set();
  51         context->toplevel = new FProfileSection();
  52         context->current = context->toplevel;
  53
  54         // return
  55         lock.Signal();
  56         return context;
  57 }
  58
  59
  60
  61 void FProfiler::Clear()
  62 {
  63     // get lock
  64     lock.Wait();
  65     // delete everything
  66     for ( int i=0; i<contexts.size(); i++ )
  67     {
  68         delete contexts[i];
  69     }
  70     contexts.clear();
  71
  72     // done
  73     lock.Signal();
  74
  75 }
  76
  77 void FProfiler::SectionPush(const std::string &name)
  78 {
  79         FProfileContext* context = GetContext();
  80         assert( context->current );
  81
  82         // try to grab the section out of the db
  83         // we store by name so that we can accumulate results over multiple frames
  84         FProfileSection* s = context->current->children[name];
  85         if ( s == NULL )
  86         {
  87                 s = new FProfileSection();
  88                 s->parent = context->current;
  89                 s->name = name;
  90                 context->current->children[name] = s;
  91         }
  92
  93         // shift current to us
  94         context->current = s;
  95
  96         // store start time
  97         context->current->timer.SetNow();
  98 //      QueryPerformanceCounter(&s->start_time);
  99
 100 }
 101
 102
 103 void FProfiler::SectionPop()
 104 {
 105     end_time.SetNow();
 106
 107         // grab the section
 108         FProfileContext* context = GetContext();
 109         FProfileSection* s = context->current;
 110
 111     // check we're not popping up too far
 112         if ( context->current->parent == NULL )
 113         return;
 114
 115         // get time for this run in ms
 116 /*      LARGE_INTEGER freq;
 117         QueryPerformanceFrequency(&freq);
 118         double time = 1000*(double)(stop_time.QuadPart - s->start_time.QuadPart)/(double)freq.QuadPart;
 119         */
 120     double time = (end_time-s->timer).ToMillis();
 121     //double time = end_time.ToMillis()-s->timer.ToMillis();
 122
 123
 124         // work out the new avg time and increment the call count
 125         double total_time = time + s->avg_time * s->call_count++;
 126         s->avg_time = total_time/(double)s->call_count;
 127         /*s->avg_time = (s->avg_time*7 + time)/8;
 128         s->call_count = 8;*/
 129
 130         // shift current up
 131         context->current = context->current->parent;
 132 }
 133
 134 void FProfiler::Display( FProfiler::SORT_BY sort )
 135 {
 136         printf("---------------------------------------------------------------------------------------\n" );
 137     // re-use formatting from individual lines
 138     printf( "PRofiler output: sorted by %s\n", (sort==SORT_EXECUTION?"execution order":"total time"));
 139     printf( "%-50s  %10s  %10s  %6s\n", "name                            values in ms -> ", "total ", "average ", "count" );
 140     printf("---------------------------------------------------------------------------------------\n" );
 141         lock.Wait();
 142         for ( FProfileContexts::iterator i = contexts.begin();
 143                   i != contexts.end();
 144                   ++i )
 145         {
 146                 printf("Thread %x\n", (unsigned int)&((*i)->thread_context) );
 147                 (*i)->toplevel->Display("| ", sort );
 148         }
 149         lock.Signal();
 150         printf("---------------------------------------------------------------------------------------\n" );
 151 }
 152
 153
 154 FProfileSection::FProfileSection()
 155 {
 156         parent = NULL;
 157         avg_time = 0;
 158         call_count = 0;
 159         exec_order_id = EXEC_ORDER_ID++;
 160 }
 161
 162 FProfileSection::~FProfileSection()
 163 {
 164     for ( FProfileSections::iterator i = children.begin();
 165         i != children.end();
 166         ++i )
 167     {
 168         delete (*i).second;
 169     }
 170     children.clear();
 171 }
 172
 173 bool reverse_time_comparator( FProfileSection* a, FProfileSection* b )
 174 {
 175     return a->avg_time*a->call_count > b->avg_time*b->call_count;
 176 }
 177
 178 bool execution_order_comparator( FProfileSection* a, FProfileSection* b )
 179 {
 180     return a->exec_order_id < b->exec_order_id;
 181 }
 182
 183 void FProfileSection::Display( const std::string& prefix, FProfiler::SORT_BY sort_by )
 184 {
 185     std::vector<FProfileSection* > children_vect;
 186         for ( FProfileSections::iterator i = children.begin();
 187                   i!= children.end();
 188                   ++i )
 189         {
 190         children_vect.push_back( (*i).second );
 191         }
 192
 193     // sort by ..
 194     if ( sort_by == FProfiler::SORT_TIME )
 195     {
 196         std::sort( children_vect.begin(), children_vect.end(), reverse_time_comparator );
 197     }
 198     else if ( sort_by == FProfiler::SORT_EXECUTION )
 199     {
 200         std::sort( children_vect.begin(), children_vect.end(), execution_order_comparator );
 201     }
 202
 203     for ( int i=0; i<children_vect.size(); i++ )
 204     {
 205         FProfileSection* sect = children_vect[i];
 206             // replace '+' with '|';
 207                 std::string name;
 208                 if ( prefix.size()>1 )
 209             name = prefix.substr( 0, prefix.size()-2 ) + std::string("+ ") + sect->name;
 210         else
 211             name = sect->name;
 212                 printf( "%-50s  %10.2f  %10.5f  %6d\n", name.c_str(),
 213                                   sect->avg_time * sect->call_count,
 214                                   sect->avg_time, sect->call_count );
 215
 216         // if this is the last child,
 217         std::string next_prefix = prefix;
 218         if ( prefix.size() > 1 && i==children_vect.size()-1 )
 219         {
 220             // erase the previous "| " and replace with "  "
 221             next_prefix = next_prefix.substr(0, next_prefix.size()-2 ) + std::string("  ");
 222         }
 223         // next deeper level
 224         sect->Display( next_prefix + "| ", sort_by );
 225
 226         }
 227 }