Welcome, Guest. Please login or register. Did you miss your activation email?

Author Topic: Trying to understand slow calls to RenderWindow::display  (Read 2898 times)

0 Members and 1 Guest are viewing this topic.

Heinrich

  • Guest
Trying to understand slow calls to RenderWindow::display
« on: October 13, 2013, 12:42:43 am »
In my search for narrowing down occasional stuttering/lag when moving a sprite and have some questions about RenderWindow::display. I have logged how long it takes to make that call when just drawing some circles and this is what I have found:

Starting dump...
Duration: 0ms.  Nr of occurrences: 8237
Duration: 1ms.  Nr of occurrences: 1722
Duration: 2ms.  Nr of occurrences: 19
Duration: 3ms.  Nr of occurrences: 2
Duration: 4ms.  Nr of occurrences: 1
Duration: 7ms.  Nr of occurrences: 3
Duration: 8ms.  Nr of occurrences: 3
Duration: 9ms.  Nr of occurrences: 5
Duration: 10ms. Nr of occurrences: 1
Duration: 14ms. Nr of occurrences: 1
Duration: 15ms. Nr of occurrences: 2
Duration: 17ms. Nr of occurrences: 1
Duration: 20ms. Nr of occurrences: 1
Duration: 25ms. Nr of occurrences: 1
Duration: 27ms. Nr of occurrences: 1
Done.
 

What we see is that the vast majority of calls to RenderWindow::display takes 0 to 1 millisecond. That's great. But there are 19 frames that takes longer than 5ms (sum occurrences taking 7-27ms). Those are what's bothering me when trying to scroll things smoothly over the screen. It just isn't smooth. I get the occational "jump" or lag when these slower frames occur. It's definitely noticeable.

Are these occational slow calls to RenderWindow::display expected behaviour? Is there any way I can prevent it? Please note that I have only measured the time it takes to call RenderWindow::display. I.e. after all the circles have been drawn to the window.

Here's the program that produces the above output. It draws 100 circles 5000 times and records how long it takes to make the RenderWindow::display call.

#include <SFML/Graphics.hpp>
#include <iostream>

using namespace std;

#define ITERATIONS (10000)

int main()
{
        srand (time(NULL));

        sf::RenderWindow window(sf::VideoMode(1024, 768), "SFML works!");

        sf::Clock clock;

        vector<sf::CircleShape*> shapes;
        for (int i = 0; i < 100; i++)
        {
                sf::CircleShape* pShape = new sf::CircleShape(50.f);
                pShape->setFillColor(sf::Color::Green);
                shapes.push_back(pShape);
        }

        map<int, int> map;

        int iBefore;
        int iAfter;

    for (int i=0;i<ITERATIONS;i++)
    {

        sf::Event event;
        while (window.pollEvent(event))
        {
            if (event.type == sf::Event::Closed)
                        {
                window.close();
                                break;
                        }
        }

        window.clear();

                for(auto iter = shapes.begin(); iter != shapes.end(); ++iter)
                {
                        sf::CircleShape* pCircle = *iter;
                        pCircle->setPosition((float)(rand() % 1000), (float)(rand() % 1000));
                        window.draw(*pCircle);
                }

                iBefore = clock.getElapsedTime().asMilliseconds();

                window.display();

                iAfter = clock.getElapsedTime().asMilliseconds();

                int iDuration = iAfter - iBefore;

                if (map.find(iDuration) == map.end())
                {
                        map[iDuration] = 1;
                }
                else
                {
                        map[iDuration] = map[iDuration]+1;
                }
    }

        cout << "Starting dump..." << endl;

        for (auto iter = map.begin(); iter != map.end(); iter++)
        {
                cout << "Duration: " << iter->first << "ms.\tNr of occurrences: " << iter->second << endl;
        }

        cout << "Done." << endl;

    return 0;
}
 

I'm running Windows 7. Quad core cpu. 8GB ram. AMD Radeon 7770. SFML 2.1. Dynamic linking of the DLLs.
« Last Edit: October 13, 2013, 12:46:39 am by Heinrich »

Ixrec

  • Hero Member
  • *****
  • Posts: 1241
    • View Profile
    • Email
Re: Trying to understand slow calls to RenderWindow::display
« Reply #1 on: October 13, 2013, 01:36:18 am »
Since it only happened a dozen times out of 10000 my guess would be expected behavior.  These are the results I get on my machine:
Starting dump...
Duration: 0ms.  Nr of occurrences: 111
Duration: 1ms.  Nr of occurrences: 4569
Duration: 2ms.  Nr of occurrences: 5250
Duration: 3ms.  Nr of occurrences: 35
Duration: 4ms.  Nr of occurrences: 12
Duration: 5ms.  Nr of occurrences: 5
Duration: 6ms.  Nr of occurrences: 3
Duration: 7ms.  Nr of occurrences: 1
Duration: 8ms.  Nr of occurrences: 4
Duration: 10ms. Nr of occurrences: 1
Duration: 11ms. Nr of occurrences: 1
Duration: 12ms. Nr of occurrences: 1
Duration: 13ms. Nr of occurrences: 2
Duration: 15ms. Nr of occurrences: 1
Duration: 16ms. Nr of occurrences: 3
Duration: 32ms. Nr of occurrences: 1
Done.
So if I'm reading this right, my machine's display() calls are slower on average but also more consistent.

Also, if you look at the source code display() on Windows is basically just a SwapBuffers() call (edit: turns out it's equally concise on Mac and Linux), so this is probably dependent on OS/driver/card and there's not a whole lot you can do about it.
« Last Edit: October 13, 2013, 01:45:19 am by Ixrec »

binary1248

  • SFML Team
  • Hero Member
  • *****
  • Posts: 1405
  • I am awesome.
    • View Profile
    • The server that really shouldn't be running
Re: Trying to understand slow calls to RenderWindow::display
« Reply #2 on: October 13, 2013, 01:47:09 am »
As Ixrec already said, the only thing that really happens in that .display() call is SwapBuffers(). Depending on how long the operating system takes to return from that call, you will get different times. This whole "benchmark" doesn't time "draw speed" at all because no "drawing" is done between those calls to .getElapsedTime(). When you call .draw() SFML queues up OpenGL commands and depending on how the driver chooses to dispatch them, it will do so immediately or wait for a more opportune moment to do so. SwapBuffers() implicitly calls glFlush() to make sure all queued commands are executed before swapping front and back buffers but drawing to the back buffer might have already been completed at that time.

If you ran the same benchmark testing some other operating system call or OpenGL call, you most probably will get the same results. You might even get the same distribution testing an empty while loop...

If you really want to test how long OpenGL and hence SFML takes to draw something and where these spikes come from, you need to time whole frames. You can be sure that between calls to SwapBuffers() everything you do has to be queued and completed by OpenGL. Any intraframe timing information is unreliable.

As for your scrolling issues... the problem is that you aren't binding the processing of your application e.g. movement to the true elapsed time. A typical approach would be to measure how much time has passed and perform normalized advancements based on that. Your application will never run at a fixed framerate, however measuring the elapsed time and working based on that will make it function even when every second frame takes 10x as long. There are so many other posts regarding this issue, so have a look on the forum, I don't feel the need to repeat what has already been said countless times.
SFGUI # SFNUL # GLS # Wyrm <- Why do I waste my time on such a useless project? Because I am awesome (first meaning).

AlexAUT

  • Sr. Member
  • ****
  • Posts: 396
    • View Profile
Re: Trying to understand slow calls to RenderWindow::display
« Reply #3 on: October 13, 2013, 02:07:29 am »
Read this, in my opinion very good, article, then you should know how to avoid the lagging scroll-movement.

http://www.koonsolo.com/news/dewitters-gameloop/


AlexAUT

Heinrich

  • Guest
Re: Trying to understand slow calls to RenderWindow::display
« Reply #4 on: October 13, 2013, 11:42:13 am »
What originally got me to look into this was that I noticed that drawing very little makes the call to RenderWindow::display faster and drawing a lot makes it slower. I.e. there's more to that call than just swapping two buffers.

Here's the times for 1 circle 5000 times. Only 3 calls takes longer than 5ms.
Starting dump...
Duration: 0ms.  Nr of occurrences: 8634
Duration: 1ms.  Nr of occurrences: 1352
Duration: 2ms.  Nr of occurrences: 9
Duration: 3ms.  Nr of occurrences: 2
Duration: 11ms. Nr of occurrences: 2
Duration: 31ms. Nr of occurrences: 1
Done.

Here's the times for 1000 circles 5000 times. A whooping 45 calls takes longer than 5ms.
Starting dump...
Duration: 0ms.  Nr of occurrences: 7163
Duration: 1ms.  Nr of occurrences: 2750
Duration: 2ms.  Nr of occurrences: 28
Duration: 3ms.  Nr of occurrences: 9
Duration: 4ms.  Nr of occurrences: 5
Duration: 5ms.  Nr of occurrences: 2
Duration: 6ms.  Nr of occurrences: 1
Duration: 7ms.  Nr of occurrences: 1
Duration: 10ms. Nr of occurrences: 1
Duration: 11ms. Nr of occurrences: 3
Duration: 12ms. Nr of occurrences: 2
Duration: 13ms. Nr of occurrences: 5
Duration: 14ms. Nr of occurrences: 4
Duration: 15ms. Nr of occurrences: 4
Duration: 16ms. Nr of occurrences: 4
Duration: 17ms. Nr of occurrences: 7
Duration: 18ms. Nr of occurrences: 5
Duration: 19ms. Nr of occurrences: 4
Duration: 20ms. Nr of occurrences: 1
Duration: 32ms. Nr of occurrences: 1
Done.

When you call .draw() SFML queues up OpenGL commands and depending on how the driver chooses to dispatch them, it will do so immediately or wait for a more opportune moment to do so. SwapBuffers() implicitly calls glFlush() to make sure all queued commands are executed before swapping front and back buffers but drawing to the back buffer might have already been completed at that time.

This explains why those times can differ. It's not merely swapping the buffers. The queue of stuff to draw might not be empty so that queue needs to be handled first.

Thank you all for your answers. It was fun digging into this and I have a better understanding of how it works now.  :)

wintertime

  • Sr. Member
  • ****
  • Posts: 255
    • View Profile
Re: Trying to understand slow calls to RenderWindow::display
« Reply #5 on: October 14, 2013, 12:47:00 am »
You could try glFinish() and see if the display method produces more consistent timing then, but only for satisfying your curiosity with a little more testing, as it slows your program down.
Still the other people are right, you shouldn't worry about that and measure the whole frames, you will have 1/60 second anyway.