Page 1 of 2

FPS hiccups profiling

Posted: Thu Feb 07, 2013 4:02 pm
by Assaf Raman
I have been working in the last few weeks on a very annoying issue, a project I am working on suffers from hiccups – meaning frame loss every few frames, a random frame each let's say 300 frames. I didn't know if the problem is a CPU or a GPU issue – or perhaps both. I wanted statistics of code bottlenecks – but only of the problematic frames, the ones that take too long (the hiccup ones). I didn't find any existing tool\code to give me that information. So I decided to create some sort of profiling tool – to answer that question.

I researched using Google, and found this great piece of code:
http://floodyberry.wordpress.com/2009/1 ... profiling/

The nice thing about this code is that it is easy to use and gives you a good report that includes the full call stack of the bottlenecks, and more impotently – you can define exactly what part of the code to profile. You need to add a macro def to the start of each function you want to profile – and when you close the program – you get an HTML table of the bottlenecks. (You can also start and stop+get the report in in the middle of the program execution if needed).
That was very helpful to find bottlenecks, but not the special "FPS hiccups" bottlenecks.

I improved the code (modified code is attached to this post).
My idea is to store the statistics of each frame on the side – and at the end of the frame – if the frame takes longer than a predefined time – add it to "hiccups statistics", in any case – clear the bucket each frame.
This really helped me out and I was able to find the reasons for the hiccups.

The way to use it is such:
I defined __PROFILER_ENABLED__
I call PROFILE_START_PROFILING at the beginning.
I call PROFILE_DUMP_REPORT_AS_HTML at the end.
At each frame end I check how long it took and call PROFILE_ADD_TO_HICCUP_STAT or PROFILE_ADD_TO_NOT_HICCUP_STAT accordingly.

I needed to add PROFILE_SCOPED(); at the beginning of each of the function I wanted to profile, this was a lot of effort.

If we want to add built in support for this profiler in OGRE we will need to add some "OGRE_START_FUNCTION" macro or the sort to all of our function – making the code dirty, but also easier to profile.

This work is far from being complete, but it is a nice start and useful in many cases.

BTW: Everything here is currently windows only, 32 bit.

That’s about it, what do you think? Useful? Should we add it to OGRE in any way? Should we add all the function start macros?

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 4:14 pm
by PhilipLB
This sounds very interesting. Have you found out, where the hickups are coming from?

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 4:32 pm
by bstone
My experience is that adding those macros to all functions/methods will mess up the code big time, especially inline functions. Since looking at the code is what you usually do much more often than profiling, that might become a real hassle.

I usually add it from scratch every time I'm seriously puzzled with something like you've been tackling. But I start with a few places at the top level, then narrow it down by descending into potentially problematic places based on the gathered stats from the previous modification.

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 4:41 pm
by Assaf Raman
@PhilipLB: Yes, an issue with the RTSS and my terrain engine - it keep creating shaders, Mattan has an idea to create a template system to overcame that issue, but my solution is good for any code project.

@bstone: I agree with you, but if you really don't like it - you can always "replace all XXX_MACRO" with nothing - then get back the clean code, profiling and dealing with bottlenecks in gaming is such a big part of the work, so it may be a price we should pay (adding the macro).

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 4:57 pm
by bstone
Maybe rework PROFILE_SCOPED() into something that could use /Gh and /GH Visual C++ compiler options? I guess GCC should have something like that too. Should be easy - have a vector working like a stack container somewhere and put those suckers on that stack in _penter(), then remove in _pexit(). That will preserve the logic. The stack dump will have an extra call but that's minor.

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 5:09 pm
by Assaf Raman
No clue - I use visual studio and may be limited because of it.

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 5:10 pm
by Assaf Raman
Perhaps some program that will add the macro to the source - and you will use it only when profiling...

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 5:21 pm
by Mikachu
Assaf Raman wrote:Perhaps some program that will add the macro to the source - and you will use it only when profiling...
Things are getting interesting! :D

I was about to suggest the same thing, but thought it would be too complex.

Maybe it's time to see what libclang is able to do in this field? (like getting the position in source code of each function implementation?)
Or maybe a naive parser would just be enough for that..

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 5:32 pm
by Assaf Raman
Well, in OGRE our functions definitions have some coding standard, it may be easy to fix the code where the coding standard is not like the rest - then write a simple program that finds the next "{" after each

Code: Select all

//-------------------------------------
in the code...

You get the idea...

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 5:35 pm
by bstone
Assaf Raman wrote:No clue - I use visual studio and may be limited because of it.
I proposed that exactly for Visual C++ which is what Visual Studio uses. The /Gh switch will make Visual C++ inject a call to _penter() at the start of every function generated by the compiler, /GH will make a call to _pexit() at the function exit. _penter/_pexit are user defined functions.

I didn't touch GCC for quite a while but quick googling tells me that it has the -finstrument-functions switch that exposes the same functionality. So that might be a good solution after all.

Re: FPS hiccups profiling

Posted: Thu Feb 07, 2013 6:43 pm
by Assaf Raman
Wow - nice - this can be the best solution! Thanks for posting, I will try it out.

Re: FPS hiccups profiling

Posted: Fri Feb 08, 2013 4:05 am
by mkultra333
It's not the GPU command buffer, is it? Might be worth testing.

Re: FPS hiccups profiling

Posted: Fri Feb 08, 2013 12:10 pm
by Assaf Raman
What do you mean? How?

Re: FPS hiccups profiling

Posted: Fri Feb 08, 2013 3:59 pm
by mkultra333
I've posted before about the GPU command buffer and the problems that it can cause and, with tweaking, problems it can fix. http://www.ogre3d.org/forums/viewtopic.php?f=5&t=50486
Tweaking the number of buffers has let me solve problems with input lag on a one card system, erratic framerates on a dual card SLI system, and 3DVision culling issues on a stereoscopic SLI system. (Short version: 2 buffered frames worked better than the default 3).

Perhaps more relevant to your issue, this user had a problem with frame rate spikes that was traced to the GPU command buffer. http://www.ogre3d.org/forums/viewtopic.php?f=2&t=74307

Not saying this is your issue, I don't know, just thought I'd mention it since the GPU command buffer can sometimes play havoc with framerates. At the very least, maybe it'd be interesting to see what happens if you set the GPU buffers to just one. Performance would go downhill, but it might help trace where the missing frame happens, since you'll have a nice one-to-one link between the CPU telling a frame to render and actually having the GPU render it.

Re: FPS hiccups profiling

Posted: Fri Feb 08, 2013 5:42 pm
by Assaf Raman
Thanks, will have a look.

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 10:37 am
by Assaf Raman
Regarding the _penter Hook Function - I am having issues getting the calling function name.
Looking into the solutions suggested here:
http://stackoverflow.com/questions/2281 ... -a-project

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 11:59 am
by bstone
Hmm. I thought the profiling code you used analyzed the call stack. Does it still need the calling function name?

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 12:32 pm
by Assaf Raman

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 1:04 pm
by Assaf Raman
The code I used - uses the __FUNCTION__ predefined macro to get current function name.
The downside is that I need to add a macro to all my function - making my code dirty - and also a lot of work.
I wanted to use the /Gh (Enable _penter Hook Function) compiler option - but it doesn't give you the function name (the gcc equivalent does give you a parameter you can use to find out the calling function).
I found this article: "A Simple Profiler using the Visual Studio C/C++ Compiler and DIA SDK" - that includes a mix of assembly and the DIA SDK to get the calling function name.
This is great - because I think I can mix it into the code I used - to get the same nice result - but without having to add so much macros to all my code.

Will try to merge both code bases now.

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 5:21 pm
by Assaf Raman
Got it to work on a sample project (code is dirty - but it works) - attached.
Will now try to use on OGRE.

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 6:14 pm
by Assaf Raman
Got this basically to work with the sample browser (didn't call PROFILE_ADD_TO_HICCUP_STAT yet) - attached is a first sample file (call stack also doesn't work for now).

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 6:30 pm
by Assaf Raman
Sec, seems that I missed that cmake removed my "/Gh /GH " flags, recompiling and retrying.

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 6:45 pm
by Assaf Raman
Call stack does- you just need to add the img folder to the same folder as the HTML report.

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 6:51 pm
by Assaf Raman
I was able to create a full report of the OGRE sample browser, sort of a big file.
Hard to find a browser that will open such a big HTML file...
Here it is: https://docs.google.com/file/d/0BzHCK1h ... sp=sharing

I guess I need to work on formatting the HTML to a few files with some javascript magic to load them on request.
Will love ideas.
A new tool to view the result?

Re: FPS hiccups profiling

Posted: Mon Feb 11, 2013 7:20 pm
by al2950
A have been following this post with interest. Looks really good so far, although chrome gave up on the 2GB html file! Will have a closer look when I get home.

Nice work! :D