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