Need help fixing / optimizing rendering

Problems building or running the engine, queries about how to use features etc.
Post Reply
MattStevens
Goblin
Posts: 239
Joined: Mon Apr 07, 2008 10:27 pm

Need help fixing / optimizing rendering

Post by MattStevens » Fri Nov 02, 2012 11:09 pm

I started having a really strange issue with the FPS of my game. I'm using 1.7.2, pretty much default build. The framerate is spiking every 4 or 5 frames, making the game looks really silly. To debug this issue I launched NVPerfHUD but I do not seem to find the issue. Here's a screenshot of my debug info and you can see the obvious spiking (bottom diagram, yellow line is the time per frame (in ms)). If you are wondering, this is a close-up of an ocean. I don't know where to start looking to understand and fix this issue. Any help is welcomed.

Image

- Matt
0 x

User avatar
Jabberwocky
OGRE Moderator
OGRE Moderator
Posts: 2819
Joined: Mon Mar 05, 2007 11:17 pm
Location: Canada
Contact:

Re: Need help fixing / optimizing rendering

Post by Jabberwocky » Sat Nov 03, 2012 12:46 am

If I were in your shoes, I'd do two things.

1. Make sure it's a problem with your ogre app, and not that specific computer.

I'd run the app on other machines, and see if the behaviour is reproduced on other machines.

2. Do some performance testing to find out what code is causing the problem.

This is what perf testing software is for. It can be kind of expensive, but you might even get away with a free 1-month trial to solve your problem.

Alternatively, you can just insert timer code directly into your code base, for free.
Here's some example timer code I use.
IMPORTANT: I have not cleaned it up for general use. You'll need to edit it to make it compile. But it might help as a base for your own code if you need it.

Code: Select all

class TimerDiagnostics
{
public:
   TimerDiagnostics();

   unsigned long m_msStartTime;
   unsigned long m_msElapsed;
   unsigned long m_msHitchTime;
   unsigned long m_msHitchLength;
};

class DiagnosticsSystem
{
   // ... <snip> ...

public:
   // This is used to gather stats on how long per-tick operations take,
   // like physics or graphics.
   // You can use this to measure anything, as long as you make sure to call
   // StartTime and StopTime together in pairs.
   void StartTimer( const String& i_strID );
   void StopTimer( const String& i_strID );
   void SetDisplayTimerDiagnostics( bool i_bDisplay );
   String FormatTimerDiagnostics() const;

private:
   std::map< String, TimerDiagnostics > m_mapTimerDiagnostics;
   bool m_bDisplayTimerDiagnostics;

Code: Select all

void DiagnosticsSystem::StartTimer( const String& i_strID )
{
   // Don't bother unless we've enabled timer diagnostics.
   if ( !m_bDisplayTimerDiagnostics )
   {
      return;
   }

   std::map< String, TimerDiagnostics >::iterator it = m_mapTimerDiagnostics.find( i_strID );

   if ( it == m_mapTimerDiagnostics.end() )
   {
      TimerDiagnostics diag;
      // The following GetTimer function returns an Ogre::Timer
      diag.m_msStartTime = TimeSys()->GetTimer().getMillisecondsCPU();
      m_mapTimerDiagnostics[ i_strID ] = diag;
   }

   else
   {
      TimerDiagnostics& diag = it->second;
      diag.m_msStartTime = TimeSys()->GetTimer().getMillisecondsCPU();
   }
}


void DiagnosticsSystem::StopTimer( const String& i_strID )
{
   // Don't bother unless we've enabled timer diagnostics.
   if ( !m_bDisplayTimerDiagnostics )
   {
      return;
   }

   std::map< String, TimerDiagnostics >::iterator it = m_mapTimerDiagnostics.find( i_strID );

   if ( it == m_mapTimerDiagnostics.end() )
   {
      // This could happen if we've enabled timer diagnostics in between a StartTimer and
      // StopTimer call.  We'll just ignore this StopTimer call, and things will work out
      // next frame.
      return;
   }

   unsigned long msNow = TimeSys()->GetTimer().getMillisecondsCPU();

   // Calculate the elapsed time
   TimerDiagnostics& diag = it->second;
   diag.m_msElapsed = msNow - diag.m_msStartTime;

   // Clear out any old hitch times.
   const unsigned long msHitchClear = 2000;  // clear hitches after 2 seconds
   if ( msNow > diag.m_msHitchTime + msHitchClear )
   {
      diag.m_msHitchTime = 0;
      diag.m_msHitchLength = 0;
   }

   // Is this the longest hitch?
   if ( diag.m_msElapsed > diag.m_msHitchLength )
   {
      diag.m_msHitchLength = diag.m_msElapsed;
      diag.m_msHitchTime = msNow;
   }
}


void DiagnosticsSystem::SetDisplayTimerDiagnostics( bool i_bDisplay )
{
   m_bDisplayTimerDiagnostics = i_bDisplay;
}


String DiagnosticsSystem::FormatTimerDiagnostics() const
{
   std::stringstream ssTimer;
   ssTimer << "Timer Diagnostics" << std::endl;

   std::map< String, TimerDiagnostics >::const_iterator it = m_mapTimerDiagnostics.begin();

   for ( ; it != m_mapTimerDiagnostics.end(); ++it )
   {
      const String& strID = it->first;
      const TimerDiagnostics& diag = it->second;

      // Skip anything that is 0 ms
      if ( diag.m_msElapsed == 0 && diag.m_msHitchLength == 0 ) continue;

      ssTimer << std::setw(12) << strID << ":  t=" << std::setw(3) << diag.m_msElapsed << " h=" << std::setw(3) << diag.m_msHitchLength << std::endl;
   }

   Viewport* pViewport = CameraSys()->GetViewport();
   if ( pViewport && pViewport->getTarget() )
   {
      ssTimer << "Batch Count: " << pViewport->getTarget()->getBatchCount() << std::endl;
   }

   return ssTimer.str();
}

So now, if I want to see how long a specific section of code takes, I insert StartTimer and StopTimer calls like this:

Code: Select all

   // ...
   static String strTimerID( "Graphics" );
   DiagnosticsSys()->StartTimer( strTimerID );

   m_pOgreRoot->renderOneFrame();

   DiagnosticsSys()->StopTimer( strTimerID );
   // ...
It's generally used for code which gets called once every frame.
You can print all the current timer info using the DiagnosticsSystem::FormatTimerDiagnostics() function, say into a text UI element, or an ogre overlay.
0 x
Image

User avatar
areay
Bugbear
Posts: 819
Joined: Wed May 05, 2010 4:59 am
Location: Auckland, NZ

Re: Need help fixing / optimizing rendering

Post by areay » Sat Nov 03, 2012 2:09 am

Thanks for sharing that Jabberwocky, I may have to turn that into a Wiki article if you don't mind :)
0 x

User avatar
thebluefish
Gremlin
Posts: 170
Joined: Tue Apr 05, 2011 1:55 am

Re: Need help fixing / optimizing rendering

Post by thebluefish » Sat Nov 03, 2012 2:31 am

I have a similar profiling system, but using Boost's timer instead :D

The biggest thing I can suggest to optimize rendering is to decouple your rendering from game logic. Though it takes a bit more effort to do so, it's a very nice thing to have seperate threads for rendering and logic. Don't get thread-happy and start spawning a thread for each different task though, "logic" and "graphics" threads are really the most you need unless your game gets complicated.
0 x
During the code inspection, a couple of minor points were noticed: -

Function inlining was critical to performance.
For MSVC, at least, a "delete 0" caused execution of 11 assembly instructions, including a function call. So in cases where performance is at an absolute premium it can be worth inserting the extra manual test.

User avatar
mkultra333
Gold Sponsor
Gold Sponsor
Posts: 1889
Joined: Sun Mar 08, 2009 5:25 am
x 36

Re: Need help fixing / optimizing rendering

Post by mkultra333 » Sat Nov 03, 2012 3:13 am

I sometimes see a bit of spiking when I run my program windowed instead of fullscreen.
Another thing that might be worth checking is gpu buffer flushing. http://www.ogre3d.org/forums/viewtopic. ... ffer+flush
0 x
"In theory there is no difference between practice and theory. In practice, there is." - Psychology Textbook.

User avatar
saejox
Goblin
Posts: 260
Joined: Tue Oct 25, 2011 1:07 am

Re: Need help fixing / optimizing rendering

Post by saejox » Sat Nov 03, 2012 3:33 am

i see a lot people have their own profiling libraries.

i used to have one based on boost timer. pretty accurate, but hard to use.

then i discovered this. http://shinyprofiler.svn.sourceforge.ne ... ler/trunk/
it a C macro library. it even has a ogre interface.
so easy to use,

Code: Select all

PROFILE_FUNC();
that's it. function is now profiled.
i recommend it.
0 x
Nimet - Advanced Ogre3D Mesh/dotScene Viewer
asPEEK - Remote Angelscript debugger with html interface
ogreHTML - HTML5 user interfaces in Ogre

bstone
OGRE Expert User
OGRE Expert User
Posts: 1920
Joined: Sun Feb 19, 2012 9:24 pm
Location: Russia

Re: Need help fixing / optimizing rendering

Post by bstone » Sat Nov 03, 2012 6:49 am

As long as profiling goes the simplest thing would be compiling your project with

Code: Select all

#define OGRE_PROFILING 1
then use this:

Code: Select all

void someFunction()
{
    OgreProfile( "someFunction()" );

    ... // some code

    if( condition )
    {
        OgreProfile( "someFunction(): branch 1" );
        ... // more code
    }
}
There are a few other handy macros defined in OgreProfiler.

But the last time I answered a similar question the problem was some pesky "performance improvement" application so it's the first thing to double check and get rid of.
0 x

Knotanalt
Halfling
Posts: 94
Joined: Sun Jul 01, 2012 2:58 pm

Re: Need help fixing / optimizing rendering

Post by Knotanalt » Sat Nov 03, 2012 8:44 am

I'd first try to figure out if you get the same problems with other scenes, and as suggested on different computers.

Just trying to profile won't help at all for many problems. It's doubtful it's a problem with your code per se, probably either hardware or particular scene detail or something in the engine, at least that's always the case for me if I get something weird like that.
0 x

MattStevens
Goblin
Posts: 239
Joined: Mon Apr 07, 2008 10:27 pm

Re: Need help fixing / optimizing rendering

Post by MattStevens » Sun Nov 04, 2012 5:13 pm

Thank you all for the input, it's very much appreciated. I forgot to mention in my first post that we are using DirectX9 renderer and I think it is important to know because related to my problem.

@Everyone: Looks like everyone has their own profiling code, hehe. We have rolled our own solution where I work as well to profile our engine. For Ogre profiling we use the already existing solution with OGRE_PROFILING, like bstone suggested. Our profiling tells me it is the rendering that causes issues (the call to Ogre::RenderWindow::update, basically the Ogre rendering of the scene). We also compiled Ogre with the define OGRE_PROFILING and the result is that the spike happens when calling IDirect3DDevice9::Present. The spike also happens every 4-5 frames or so. From what I understand, DirectX can "stack" up to 4 frames on the GPU, meaning Present will return even if the frame is not over. However, is you reach 4 stacked frames, Present will block until all of them are processed, then return for your main loop to continue, thus causing a noticable "lag spike". This would explain my issue and the spike that happens at regular intervals. This would mean that I send "too much" stuff to the graphic card and it just can't render fast enough before the next frames arrives. I never had to deal with this before and wonder if someone have experience

@Jabberwocky: The problem is present on every computer we run the software, so it's probably not driver / hardware specific. We tried multiple graphic cards and CPU / motherboard combination. The problem is persistent.

@thebluefish: Decoupling game logic and rendering is separate thread is not doable, not at the stage we are in. This is definitely something we are looking for our next engine.

@mkultra333: Software runs in full screen mode, no VSync. The actual product is supposed to run on 4 screens, however for testing we run in a single screen. The problems happens on all configuration.

@saejox: I'll look at shinyprofiler but it's probably not needed as we have our own solution already implemented.

@bstone: What exactly do you mean by "performance improvement" application. You have me confused.

@Knotanalt: We actually have 6 different "levels", the issue is only with one of them. There's a lot of differences between them, but the main one is the water with real-time reflection.

Thanks again to all of you.
- Matt
0 x

bstone
OGRE Expert User
OGRE Expert User
Posts: 1920
Joined: Sun Feb 19, 2012 9:24 pm
Location: Russia

Re: Need help fixing / optimizing rendering

Post by bstone » Sun Nov 04, 2012 5:40 pm

Here: Frame rate hiccup on Windows. That issue actually was the second time somebody used that crap :)

But what you say about Present() sounds like the GPU buffer flushing issue indeed. Refer to the thread mkultra333 brought up.
0 x

MattStevens
Goblin
Posts: 239
Joined: Mon Apr 07, 2008 10:27 pm

Re: Need help fixing / optimizing rendering

Post by MattStevens » Sun Nov 04, 2012 6:09 pm

I read the whole thread 3 times and for some reason I kept skipping over mkultra333's link. It seems to be exactly the problem I have. I'll go over that thread to see if there's any solution to my problem.

- Matt
0 x

User avatar
Nickenstein79
Halfling
Posts: 50
Joined: Tue Sep 18, 2012 3:30 am

Re: Need help fixing / optimizing rendering

Post by Nickenstein79 » Sun Nov 04, 2012 7:07 pm

If you are using visual studio you could do an instrumentation build to get a hierarchy graph of all of the expensive function calls in your game.

I once thought my problem was rendering time, but an instrumentation build highlighted that I was accidentally updating my physics solution 3 times per frame from different frame listeners!
0 x

MattStevens
Goblin
Posts: 239
Joined: Mon Apr 07, 2008 10:27 pm

Re: Need help fixing / optimizing rendering

Post by MattStevens » Sun Nov 04, 2012 8:03 pm

Problem solved!
Okay, so the issue was what I mentioned in my last post. The GPU frame buffer. It is the same problem mkultra333 had back in 2009 (! See the thread link in his post).
Sinbad made a wiki page with a single classe that fix this very specific issue. Link

I implemented the class, used with it the default number of queued frame (2) and voila, spiking is gone.

I must say the stress was at an uncomfortable level lately (software release in 5 days) and you guys really help me out. Thanks a lot to everyone.

Also, from the thread about GPU frame buffer, it seems quite a lot of people uses or needs this feature and there was talk about integrating it in the core, is it done in Ogre 1.8 or later version ? This issue is very insidious because I feel it's hard to pinpoint the reason and you need a lot of research to understand why it happens and how to fix it. Just my 2 cents.

- Matt
0 x

bstone
OGRE Expert User
OGRE Expert User
Posts: 1920
Joined: Sun Feb 19, 2012 9:24 pm
Location: Russia

Re: Need help fixing / optimizing rendering

Post by bstone » Sun Nov 04, 2012 8:21 pm

That's GPU command buffer, just for purity :wink: And it won't actually happen that often because in real life the CPU doesn't go on vacation in that many projects. Just make it do some real work and it won't get ahead of the GPU that easily. If you have lots of spare cycles in your product then it's time to add some software synthesizer with a cool audio track to keep your users entertained but your CPU busy. :lol:
0 x

MattStevens
Goblin
Posts: 239
Joined: Mon Apr 07, 2008 10:27 pm

Re: Need help fixing / optimizing rendering

Post by MattStevens » Mon Nov 05, 2012 5:36 am

Gotcha, I'll remember the exact name next time. As for the CPU idling, it is definitely not the normal case. It is only in a specific level, at a specific scene that the issue appeared, so we'll go easy on new CPU heavy features ;)
0 x

Post Reply