Initial draws take much longer then the following

[Kanefa]

I have been walking through the Arkanoid in 160 lines tutorial (I don't believe knowledge of the tutorial is necessary to answer the question). I just finished the second one and started to notice my version is exhibiting some undesirable behavior. This occurs when I pass the ball and paddle function time deltas.

What happens is the first visual the player sees is further along then I would like to be. I have attached two screenshots. In the first one the ball is near the center of the screen and this is the appropriate behavior. However, in the second one the ball has already knocked out two bricks and traveled quite a bit of distance before it was ever drawn.

What I have noticed is my initial draws take a very long time compared to the following ones on the next iteration of the loop. Here is a code snippet to show what I am doing. The points of interest are where I begin timing (comment 'Start time') and finish timing ('End time').

        while (window.isOpen())
        {
                auto startFrame(std::chrono::high_resolution_clock::now()); // Start time

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

                ball.update();
                paddle.update();

                testCollision(paddle, ball);
                for (auto &brick : bricks)
                {
                        testCollision(brick, ball);
                }

                bricks.erase(std::remove_if(begin(bricks), end(bricks),
                        [](const Brick &brick){ return brick.mDestroyed; }),
                        end(bricks));

                window.clear(sf::Color::Black);
                window.draw(ball.mShape);
                window.draw(paddle.mShape);
                for (const auto &brick : bricks)
                {
                        window.draw(brick.mShape);
                }

                window.display();

                auto endFrame(std::chrono::high_resolution_clock::now()); // End time

                // Frame duration
                auto frameTime(std::chrono::duration_cast<std::chrono::duration<FrameTime, std::milli>>
                     (endFrame - startFrame).count());
        }
 

The value of 'frametime' on the initial time through the loop takes around 400-700 milliseconds. This value will be passed to the update functions and on the next draw the ball will make a huge jump and that's the undesirable behavior I am seeing. However, after this initial frame each frame then takes around 15 milliseconds and this is very expected (as it matches the tutorial).

Also, to be clear I moved around the time points and it was clear that it was the draws were taking up the bulk of the time. I believe I understand what is going on, but I am surprised. I want to ask the following questions. Should the initial draw be significantly slower than the following ones? Also, what explains the difference in Romeo's (author of tutorial) game behavior and mine? I don't think such a simple example would exasperate the fact I may be using slower computer.

[Nexus]

There is some caching in draw() that can make subsequent calls a bit faster, but I find it difficult to believe that drawing something so simple would take hundreds of milliseconds.

It would be interesting to know more exactly where the time is spent. Do you have a profiler, e.g. one built in IDEs like Visual Studio, or an external one like AMD CodeAnalyst? And more importantly, since you claim that drawing uses all of the time, can you reduce the example to a minimal one? Drawing a few shapes should reproduce that behavior, there would be no need for collision detection and brick removal.

You can also use sf::Clock for time measuring... The syntax is less verbose than Chrono, and it's more portable (VS standard libraries have failed to provide high-resolution clocks until recently).

[Kanefa]

Thanks for the response. I have started by creating a minimal example. If I set a breakpoint on the last line of the loop the 'duration' is always 400+ milliseconds on the first iteration then the following iterations are much lower around 4-20 milliseconds.

#include <SFML/Graphics/CircleShape.hpp>
#include <SFML/Graphics/Color.hpp>
#include <SFML/Graphics/RectangleShape.hpp>
#include <SFML/Graphics/RenderWindow.hpp>
#include <SFML/System/Clock.hpp>
#include <SFML/System/Vector2.hpp>

int main()
{
        sf::CircleShape circle{10.f};
        sf::RectangleShape rectangle{{60.f, 20.f }};
        sf::RenderWindow window({800, 600}, "Minimal Example");

        while (true)
        {
                sf::Clock clock;

                // Start timing
                sf::Time startTime = clock.restart();

                // "Clear" the window from previouly drawn graphics
                window.clear(sf::Color::Black);
                window.draw(circle);
                window.draw(rectangle);
                window.display();

                // End timing
                sf::Time endTime = clock.restart();
                int duration = endTime.asMilliseconds();
                int x = 0; // Set breakpoint here
        }

        return 0;
}
 

[eXpl0it3r]

There's definitely some caching and initialization going on for the first draw call.

My short example creates and destroys 50 windows and measures the first and second draw call to each window. All my values are in microseconds!

(click to show/hide)

1: 42379
2: 548
1: 13199
2: 213
1: 14690
2: 345
1: 20033
2: 389
1: 10386
2: 470
1: 15516
2: 220
1: 11867
2: 244
1: 7358
2: 190
1: 15580
2: 231
1: 11701
2: 209
1: 14256
2: 278
1: 43237
2: 12796
1: 18840
2: 258
1: 7832
2: 238
1: 11601
2: 670
1: 15648
2: 1555
1: 7355
2: 190
1: 12584
2: 248
1: 26728
2: 351
1: 18122
2: 238
1: 13504
2: 180
1: 5619
2: 390
1: 12325
2: 186
1: 19414
2: 195
1: 19543
2: 194
1: 14248
2: 221
1: 12227
2: 188
1: 12099
2: 176
1: 15982
2: 205
1: 8398
2: 182
1: 13820
2: 186
1: 9220
2: 354
1: 10493
2: 247
1: 12923
2: 191
1: 7588
2: 183
1: 19249
2: 181
1: 14218
2: 217
1: 15961
2: 192
1: 5286
2: 193
1: 15710
2: 201
1: 5798
2: 177
1: 18205
2: 201
1: 14616
2: 198
1: 12732
2: 333
1: 14581
2: 189
1: 27038
2: 343
1: 21249
2: 283
1: 15710
2: 188
1: 12053
2: 178
1: 8698
2: 539

Average:
1: 14948.4
2: 535.44

If I just start an application an measure the time for the first draw call, it will fluctuate around 39-45ms.

Personally I don't really see any issue with the first draw call taking longer. Even 400ms are over before you can blink twice.

[Kanefa]

Thanks for posting your short example. When I run your example I get the following results.

157085
1578
111925
768
91841
1373
195144
641
193948
1401
197849
679
 

I am asking this question purely from an educational point of view. The tutorial is just that, but if it was an actual game the ball would have traveled a quarter of the screen, knocked out two bricks, and ricocheted off the wall before the player could react (if they were playing on my computer).

I can work around this by doing the initial draws as part of the "initialization." That seemed weird, so I created this post.

[eXpl0it3r]

But I doubt that was only due to the 400ms delay.

Then again if your game starts just as you double click your executable it's anyways not very well made. I mean it served the purpose of keeping the LoC count low, but in an actually game that you'd pass on to someone else, the action shouldn't start before the player gives the input. I mean do you know any game you open and the first thing you see is the whole world come crashing down and you got a second to react before you lose?

[Kanefa]

But I doubt that was only due to the 400ms delay.

I am fairly certain this is the issue. The tutorial passes a constant time step to the update methods. Multiple time steps will be processed during the current frame if the previous frame was slow. Therefore, the ball's current position will move forward proportional to the previous frame's duration and then be drawn.

Considering the ball can move across the screen in about half a second it then follows that if the initial draws take half a second the ball will move across half the screen on the next frame before it is drawn.

Now I do understand what you are saying in regards to starting a game without user input, but I believe it is irrelevant. There are many instances were an object could be drawn for the first time and the game has not just started.

I have shown a very minimal example where a first clear followed by two draws and then a display takes nearly half a second on my computer. That seems like a fairly large chunk of time. I imagine if someone else runs the minimal code example I gave they'll report a much faster time. I think that explains the difference in behavior, but I am still surprised.

[eXpl0it3r]

I imagine if someone else runs the minimal code example I gave they'll report a much faster time. I think that explains the difference in behavior, but I am still surprised.

I already showed above that my initial delay is between 38-45ms and less than half of that, if I've previously had a window created.

Now I do understand what you are saying in regards to starting a game without user input, but I believe it is irrelevant. There are many instances were an object could be drawn for the first time and the game has not just started.

I still don't see an issue. I absolutely do not care about the first frame that gets rendered of any (larger) game I ever played, because it will either be some logo of the company/sponsor/whatever or it will be a menu that isn't time sensitive either.

Somewhere this initialization/caching/whatever it is needs to happen and I rather have my first frame delayed by default than getting a huge lag for every new window one creates or similar. If every single frame really matters that much, one could still go and call the functions once before starting the physics.

Until someone digs into the source code and finds out what is actually happening, or just knows it from the top of the head, there's not much sense in discussion whether it should happen at all or where it should happen.

[binary1248]

There you go. RenderTarget does lazy initialization of GL states on the first draw, how long this takes is implementation (driver/GPU) dependent. This is also all disregarding any initialization the driver/GPU might do as well when a new framebuffer is allocated.

Like eXpl0it3r said, this has absolutely no effect on any well-designed real-world application, but since you wanted to know for educational purposes, well... now you know.

[Kanefa]

I appreciate the responses. I now understand the issue and its insignificance. I was reading the "first draw" as the first draw of a unique object and not the first draw of the program.

To summarize the first draw of the program will do some initialization which will make this single draw slow. Each subsequent draw will not need to to the initialization and will run fast. The first draw is normally a splash screen or some other screen that is not time sensitive, so this is insignificant.

[Hapax]

...first draw of the program.

It would be the first draw of the window (or any render target) so each of multiple windows - for example - will all experience the same 'effect'.