1
Graphics / Random spikes in time taken to draw objects
« on: February 17, 2013, 10:56:48 am »
I've been noticing some stuttering in my game, which is kind of annoying. I did some profiling and it seemed to be centered around a section of code dealing with some render textures.
I've been able to form this minimal program:
Essentially, opens a window, makes a render texture and then draws some data to the render texture. It keeps track of the time taken to clear, draw and display each frame and saves it to an excel file. Opening it up and making a graph shows tonnes of spikes in time taken for the draw step. The loop is there to exaggerate the lag spike. Also, my game requires 5 passes, due to some shaders, so I left it in in case it affects the answer.
Here are some example runs:
My pc:
Friend's pc
As you can see, every frame is dominated by the draw time, with occassional spikes in the display time. But then, sometimes this also happens:
Note from frame 1400 onwards, the display time jumps from almost 0ms to 0.7ms, and the draw time drops from around 1.4ms down to 0.7ms. I've noticed this behaviour in my game as well, where sometimes all the rendering time is reported under my render system, and window.display() happens almost instantaneously, and other times my render system renders faster, while the window.display() takes long enough to fill the gap.
Basically, I'm looking for reasons or explanations why both the spikes and the draw/display effect is happening. I'm guessing it might have something to do with interrupts to the graphics card, or some other hardware side effect that I won't have much control over. But figured I would post and see if anyone has any ideas.
I've been able to form this minimal program:
#include <SFML/Graphics.hpp>
#include <stdio.h>
#define NUMLOOPS 2000
#define WIDTH 1600
#define HEIGHT 900
int main() {
sf::RenderWindow window( sf::VideoMode( WIDTH, HEIGHT, 32 ), "Lag Spikes" );
sf::RenderTexture renderTexture;
sf::Sprite renderSprite;
renderTexture.create(WIDTH, HEIGHT);
renderSprite.setTexture(renderTexture.getTexture());
sf::VertexArray tileDetails;
tileDetails.setPrimitiveType(sf::Triangles);
sf::Clock deltaClock;
FILE *fp;
fopen_s(&fp, "timings.xls", "w");
fprintf_s(fp, "Frame Time\tClear Time\tDraw Time\tDisplay Time\n");
srand(0);
float records[NUMLOOPS][4];
for(int i = 0; i < NUMLOOPS; i++)
{
//Frame time for previous frame
records[i][0] = deltaClock.restart().asSeconds();
window.clear(sf::Color::Cyan);
records[i][1] = deltaClock.getElapsedTime().asSeconds();
//Draw to some render textures and draw them to screen
for(int j = 0; j < 5; j++)
{
renderTexture.clear(sf::Color::Transparent);
renderTexture.draw(tileDetails);
renderTexture.display();
window.draw(renderSprite);
}
records[i][2] = deltaClock.getElapsedTime().asSeconds();
window.display();
records[i][3] = deltaClock.getElapsedTime().asSeconds();
}
//Write out the times
for(int i = 0; i < NUMLOOPS; i++)
fprintf_s(fp, "%f\t%f\t%f\t%f\n", records[i][0], records[i][1], records[i][2] - records[i][1], records[i][3] - records[i][2]);
}
#include <stdio.h>
#define NUMLOOPS 2000
#define WIDTH 1600
#define HEIGHT 900
int main() {
sf::RenderWindow window( sf::VideoMode( WIDTH, HEIGHT, 32 ), "Lag Spikes" );
sf::RenderTexture renderTexture;
sf::Sprite renderSprite;
renderTexture.create(WIDTH, HEIGHT);
renderSprite.setTexture(renderTexture.getTexture());
sf::VertexArray tileDetails;
tileDetails.setPrimitiveType(sf::Triangles);
sf::Clock deltaClock;
FILE *fp;
fopen_s(&fp, "timings.xls", "w");
fprintf_s(fp, "Frame Time\tClear Time\tDraw Time\tDisplay Time\n");
srand(0);
float records[NUMLOOPS][4];
for(int i = 0; i < NUMLOOPS; i++)
{
//Frame time for previous frame
records[i][0] = deltaClock.restart().asSeconds();
window.clear(sf::Color::Cyan);
records[i][1] = deltaClock.getElapsedTime().asSeconds();
//Draw to some render textures and draw them to screen
for(int j = 0; j < 5; j++)
{
renderTexture.clear(sf::Color::Transparent);
renderTexture.draw(tileDetails);
renderTexture.display();
window.draw(renderSprite);
}
records[i][2] = deltaClock.getElapsedTime().asSeconds();
window.display();
records[i][3] = deltaClock.getElapsedTime().asSeconds();
}
//Write out the times
for(int i = 0; i < NUMLOOPS; i++)
fprintf_s(fp, "%f\t%f\t%f\t%f\n", records[i][0], records[i][1], records[i][2] - records[i][1], records[i][3] - records[i][2]);
}
Essentially, opens a window, makes a render texture and then draws some data to the render texture. It keeps track of the time taken to clear, draw and display each frame and saves it to an excel file. Opening it up and making a graph shows tonnes of spikes in time taken for the draw step. The loop is there to exaggerate the lag spike. Also, my game requires 5 passes, due to some shaders, so I left it in in case it affects the answer.
Here are some example runs:
My pc:
Friend's pc
As you can see, every frame is dominated by the draw time, with occassional spikes in the display time. But then, sometimes this also happens:
Note from frame 1400 onwards, the display time jumps from almost 0ms to 0.7ms, and the draw time drops from around 1.4ms down to 0.7ms. I've noticed this behaviour in my game as well, where sometimes all the rendering time is reported under my render system, and window.display() happens almost instantaneously, and other times my render system renders faster, while the window.display() takes long enough to fill the gap.
Basically, I'm looking for reasons or explanations why both the spikes and the draw/display effect is happening. I'm guessing it might have something to do with interrupts to the graphics card, or some other hardware side effect that I won't have much control over. But figured I would post and see if anyone has any ideas.