1 // =============================================================================
2 // PROJECT CHRONO - http://projectchrono.org
3 //
4 // Copyright (c) 2014 projectchrono.org
5 // All rights reserved.
6 //
7 // Use of this source code is governed by a BSD-style license that can be found
8 // in the LICENSE file at the top level of the distribution and at
9 // http://projectchrono.org/license-chrono.txt.
10 //
11 // =============================================================================
12 // Authors: Alessandro Tasora
13 // =============================================================================
14
15
16 /*
17 CODE MODIFIED FROM:
18
19
20 ***************************************************************************************************
21 **
22 ** profile.cpp
23 **
24 ** Real-Time Hierarchical Profiling for Game Programming Gems 3
25 **
26 ** by Greg Hjelstrom & Byon Garrabrant
27 **
28 ***************************************************************************************************/
29
30 // Credits: The Clock class was inspired by the Timer classes in
31 // Ogre (www.ogre3d.org).
32
33 #include "chrono/core/ChTimer.h"
34 #include "chrono/utils/ChProfiler.h"
35
36 #include <ctime>
37 #include <ratio>
38 #include <chrono>
39 #include <cstdio>
40
41 namespace chrono {
42 namespace utils {
43
44 #ifndef CH_NO_PROFILE
45
46 static ChTimer<double> gProfileClock;
47
48 #define mymin(a,b) (a > b ? a : b)
49
Profile_Get_Ticks(unsigned long int * ticks)50 inline void Profile_Get_Ticks(unsigned long int * ticks)
51 {
52 *ticks = (unsigned long)gProfileClock.GetTimeMicrosecondsIntermediate();
53 }
54
Profile_Get_Tick_Rate(void)55 inline float Profile_Get_Tick_Rate(void)
56 {
57 // return 1000000.f;
58 return 1000.f;
59
60 }
61
62
63
64
65 /***************************************************************************************************
66 **
67 ** ChProfileNode
68 **
69 ***************************************************************************************************/
70
71 /***********************************************************************************************
72 * INPUT: *
73 * name - pointer to a static string which is the name of this profile node *
74 * parent - parent pointer *
75 * *
76 * WARNINGS: *
77 * The name is assumed to be a static pointer, only the pointer is stored and compared for *
78 * efficiency reasons. *
79 *=============================================================================================*/
ChProfileNode(const char * name,ChProfileNode * parent)80 ChProfileNode::ChProfileNode( const char * name, ChProfileNode * parent ) :
81 Name( name ),
82 TotalCalls( 0 ),
83 TotalTime( 0 ),
84 StartTime( 0 ),
85 RecursionCounter( 0 ),
86 Parent( parent ),
87 Child( NULL ),
88 Sibling( NULL )
89 {
90 Reset();
91 }
92
93
CleanupMemory()94 void ChProfileNode::CleanupMemory()
95 {
96 delete ( Child);
97 Child = NULL;
98 delete ( Sibling);
99 Sibling = NULL;
100 }
101
~ChProfileNode(void)102 ChProfileNode::~ChProfileNode( void )
103 {
104 delete ( Child);
105 delete ( Sibling);
106 }
107
108
109 /***********************************************************************************************
110 * INPUT: *
111 * name - static string pointer to the name of the node we are searching for *
112 * *
113 * WARNINGS: *
114 * All profile names are assumed to be static strings so this function uses pointer compares *
115 * to find the named node. *
116 *=============================================================================================*/
Get_Sub_Node(const char * name)117 ChProfileNode * ChProfileNode::Get_Sub_Node( const char * name )
118 {
119 // Try to find this sub node
120 ChProfileNode * child = Child;
121 while ( child ) {
122 if ( child->Name == name ) {
123 return child;
124 }
125 child = child->Sibling;
126 }
127
128 // We didn't find it, so add it
129
130 ChProfileNode * node = new ChProfileNode( name, this );
131 node->Sibling = Child;
132 Child = node;
133 return node;
134 }
135
136
Reset(void)137 void ChProfileNode::Reset( void )
138 {
139 TotalCalls = 0;
140 TotalTime = 0.0f;
141
142
143 if ( Child ) {
144 Child->Reset();
145 }
146 if ( Sibling ) {
147 Sibling->Reset();
148 }
149 }
150
151
Call(void)152 void ChProfileNode::Call( void )
153 {
154 TotalCalls++;
155 if (RecursionCounter++ == 0) {
156 Profile_Get_Ticks(&StartTime);
157 }
158 }
159
160
Return(void)161 bool ChProfileNode::Return( void )
162 {
163 if ( --RecursionCounter == 0 && TotalCalls != 0 ) {
164 unsigned long int time;
165 Profile_Get_Ticks(&time);
166 time-=StartTime;
167 TotalTime += (float)time / Profile_Get_Tick_Rate();
168 }
169 return ( RecursionCounter == 0 );
170 }
171
172
173 /***************************************************************************************************
174 **
175 ** ChProfileIterator
176 **
177 ***************************************************************************************************/
ChProfileIterator(ChProfileNode * start)178 ChProfileIterator::ChProfileIterator( ChProfileNode * start )
179 {
180 CurrentParent = start;
181 CurrentChild = CurrentParent->Get_Child();
182 }
183
184
First(void)185 void ChProfileIterator::First(void)
186 {
187 CurrentChild = CurrentParent->Get_Child();
188 }
189
190
Next(void)191 void ChProfileIterator::Next(void)
192 {
193 CurrentChild = CurrentChild->Get_Sibling();
194 }
195
196
Is_Done(void)197 bool ChProfileIterator::Is_Done(void)
198 {
199 return CurrentChild == NULL;
200 }
201
202
Enter_Child(int index)203 void ChProfileIterator::Enter_Child( int index )
204 {
205 CurrentChild = CurrentParent->Get_Child();
206 while ( (CurrentChild != NULL) && (index != 0) ) {
207 index--;
208 CurrentChild = CurrentChild->Get_Sibling();
209 }
210
211 if ( CurrentChild != NULL ) {
212 CurrentParent = CurrentChild;
213 CurrentChild = CurrentParent->Get_Child();
214 }
215 }
216
217
Enter_Parent(void)218 void ChProfileIterator::Enter_Parent( void )
219 {
220 if ( CurrentParent->Get_Parent() != NULL ) {
221 CurrentParent = CurrentParent->Get_Parent();
222 }
223 CurrentChild = CurrentParent->Get_Child();
224 }
225
226
227 /***************************************************************************************************
228 **
229 ** ChProfileManager
230 **
231 ***************************************************************************************************/
232
233 ChProfileNode ChProfileManager::Root( "Root", NULL );
234 ChProfileNode * ChProfileManager::CurrentNode = &ChProfileManager::Root;
235 int ChProfileManager::FrameCounter = 0;
236 unsigned long int ChProfileManager::ResetTime = 0;
237
238
239 /***********************************************************************************************
240 * ChProfileManager::Start_Profile -- Begin a named profile *
241 * *
242 * Steps one level deeper into the tree, if a child already exists with the specified name *
243 * then it accumulates the profiling; otherwise a new child node is added to the profile tree. *
244 * *
245 * INPUT: *
246 * name - name of this profiling record *
247 * *
248 * WARNINGS: *
249 * The string used is assumed to be a static string; pointer compares are used throughout *
250 * the profiling code for efficiency. *
251 *=============================================================================================*/
Start_Profile(const char * name)252 void ChProfileManager::Start_Profile( const char * name )
253 {
254 if (name != CurrentNode->Get_Name()) {
255 CurrentNode = CurrentNode->Get_Sub_Node( name );
256 }
257
258 CurrentNode->Call();
259 }
260
261
262 /***********************************************************************************************
263 * ChProfileManager::Stop_Profile -- Stop timing and record the results. *
264 *=============================================================================================*/
Stop_Profile(void)265 void ChProfileManager::Stop_Profile( void )
266 {
267 // Return will indicate whether we should back up to our parent (we may
268 // be profiling a recursive function)
269 if (CurrentNode->Return()) {
270 CurrentNode = CurrentNode->Get_Parent();
271 }
272 }
273
274
275 /***********************************************************************************************
276 * ChProfileManager::Reset -- Reset the contents of the profiling system *
277 * *
278 * This resets everything except for the tree structure. All of the timing data is reset. *
279 *=============================================================================================*/
Reset(void)280 void ChProfileManager::Reset( void )
281 {
282 gProfileClock.reset();
283 gProfileClock.start();
284 Root.Reset();
285 Root.Call();
286 FrameCounter = 0;
287 Profile_Get_Ticks(&ResetTime);
288 }
289
290
291 /***********************************************************************************************
292 * ChProfileManager::Increment_Frame_Counter -- Increment the frame counter *
293 *=============================================================================================*/
Increment_Frame_Counter(void)294 void ChProfileManager::Increment_Frame_Counter( void )
295 {
296 FrameCounter++;
297 }
298
299
300 /***********************************************************************************************
301 * ChProfileManager::Get_Time_Since_Reset -- returns the elapsed time since last reset *
302 *=============================================================================================*/
Get_Time_Since_Reset(void)303 float ChProfileManager::Get_Time_Since_Reset( void )
304 {
305 unsigned long int time;
306 Profile_Get_Ticks(&time);
307 time -= ResetTime;
308 return (float)time / Profile_Get_Tick_Rate();
309 }
310
311
dumpRecursive(ChProfileIterator * profileIterator,int spacing)312 void ChProfileManager::dumpRecursive(ChProfileIterator* profileIterator, int spacing)
313 {
314 profileIterator->First();
315 if (profileIterator->Is_Done())
316 return;
317
318 float accumulated_time = 0, parent_time = profileIterator->Is_Root()
319 ? ChProfileManager::Get_Time_Since_Reset()
320 : profileIterator->Get_Current_Parent_Total_Time();
321 int frames_since_reset = ChProfileManager::Get_Frame_Count_Since_Reset();
322 for (int i = 0; i < spacing; i++)
323 printf(".");
324 printf("----------------------------------\n");
325 for (int i = 0; i < spacing; i++)
326 printf(".");
327 printf("Profiling: %s (total running time: %.3f ms) ---\n", profileIterator->Get_Current_Parent_Name(),
328 parent_time);
329 float totalTime = 0.f;
330
331
332 int numChildren = 0;
333
334 for (int i = 0; !profileIterator->Is_Done(); i++, profileIterator->Next()) {
335 numChildren++;
336 float current_total_time = profileIterator->Get_Current_Total_Time();
337 accumulated_time += current_total_time;
338 float fraction = parent_time > FLT_EPSILON ? (current_total_time / parent_time) * 100 : 0.f;
339 for (int j = 0; j < spacing; j++)
340 printf(".");
341 printf("%d -- %s (%.2f %%) :: %.3f ms / frame (%d calls)\n", i, profileIterator->Get_Current_Name(), fraction,
342 (current_total_time / (double)frames_since_reset), profileIterator->Get_Current_Total_Calls());
343 totalTime += current_total_time;
344 // recurse into children
345 }
346
347 if (parent_time < accumulated_time) {
348 printf("what's wrong\n");
349 }
350 for (int i = 0; i < spacing; i++)
351 printf(".");
352 printf("%s (%.3f %%) :: %.3f ms\n",
353 "Unaccounted:", parent_time > FLT_EPSILON ? ((parent_time - accumulated_time) / parent_time) * 100 : 0.f,
354 parent_time - accumulated_time);
355
356 for (int i = 0; i < numChildren; i++) {
357 profileIterator->Enter_Child(i);
358 dumpRecursive(profileIterator, spacing + 3);
359 profileIterator->Enter_Parent();
360 }
361 }
362
363
364
dumpAll()365 void ChProfileManager::dumpAll()
366 {
367 ChProfileIterator* profileIterator = 0;
368 profileIterator = ChProfileManager::Get_Iterator();
369
370 dumpRecursive(profileIterator,0);
371
372 ChProfileManager::Release_Iterator(profileIterator);
373 }
374
375
376
377
378 #endif //CH_NO_PROFILE
379
380 } // end namespace utils
381 } // end namespace chrono
382