GC Lag Question

Performance Tuning
#21

Well, 1ms is certainly not important, but 50ms is probably way too obvious. Problem is not running at constant 50fps - this is probably good enough. Problem is with running at 100fps and suddenly missing 2-3 frames in row and then again running with full speed for some seconds. You can easily spot such stutter, because of the sudden change in behaviour. I would even risk saying than having 20fps constant is a lot better than having 100fps with 20-50ms breaks once per second. Of course, gc is not only thing which can cause some delays - in many games, loading the textures to GPU for a new objects can also cause stuttering, even for a longer period of time.

That said, we are running in 10 second pauses on 8 cpu machine with concurrent gc… and we are allocating modest 2-3MB of memory per second, most of it never leaving the eden space (less than 1MB promoted to old generation every 10 seconds) with total heap size of 1-1.5GB. Fortunately it is not an interactive game…

#22

:o
Do you mean that you are having 10 second long pauses due to collection of eden?
[edit] did you tune the eden, or things like that? what is the occurency of the pauses?

#23

Although a 8-cpu system should have more than 1.0-1.5 GB, did you take swapping into account? a GC over a swapped heap part is dead-slow.

I can’t think of anothre reason that would cause these slowdowns.

#24

10 second pauses during rescan phase of old generation (one of the few blocking phases of CMS). New generation pauses are generally around 100ms.
We have 16GB RAM, with many processes running, but we always have around 3GB free physical RAM on top of all them.

Few explanations why it can take so long:
We are running on 8x1200MHz Sparc. Every of these CPUs is probably a lot slower than current x86 based CPUs, especially if you take memory access into account.
We have to disable parallelism in rescan phase, as using parallel GC together with CMS is resulting in jvm crash in few hours for us (both on windows and on solaris). We are using 5.0_06, I have reported this problem to Sun, unfortunately they are not able to solve it without small, easily reproductible case.

Unfortunately, there is almost no relation between number of dirty cards during rescan and duration of pause. We sometimes get under-1s CMS pause with 30k dirty pages, and 10s pauses with 9k dirty pages.

I hope that this problem is caused by http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6367204, which is supposed to be fix in 5.0_07. Anyway, currently we are not even close to being realtime on 8 CPU machine with a lot of free memory and 20% total load on average.

#25

Im not sure I follow this, if your moving the object in a time-based rather then frame based motion unless the variation is very large I wouldnt imagine it would be noticeable. After all, flicer rate for the human eye is only about 50hz as I recall.

Wow. I find that amazing. How big is your long-lived heap? If you make you long lived heap huge it means fewer but bigger pauses collecting it.

#26

Yes, but 3 missed frames means same image displayed for 40ms (25Hz). if you have full screen moving (like turning around in FPS game) this will be extremly noticeable.
I think that LagTest posted below is quite nice test.

Around 1GB of used old heap (from 2.5GB of Xmx). We are running CMS in incremental mode, so it is running by itself every 5-10 minutes - without that, if it was running every 1 hour or so when memory was closing to a limit, we were running into minute long pauses.

#27

I made more tests with several sprites instead of just one rotating at the center. Here’s the results:


reqfps    numit     numsp     avgdraw      max       avggc    numgc
200       200       1         0.0003       0.026     0.01     1
200       200       10        0.0007       0.034     0.06     1
200       200       50        0.0015       0.036     0.014    1
100       200       100       0.003        0.041     0.014    1
50        200       200       0.005        0.031     0.012    1
50        200       400       0.02         0.07      0.017    3
20        200       1000      0.03         0.108     0.013    6

The legend:

reqfps=required fps
numit=number of iterations
numsp=number of sprites
avgdraw=average drawing time
max=maximum drawing time
avggc=average gc time
numgc=numbered of Par gcs during demo

Being able to draw 400 sprites at 50 fps and 1000 at 20 fps almost concistently is great. I also have a good machine.

I say almost concistently because of the ocasional java hickup. Like CK said concistency is very important. It doesn’t mater if this only hapens every 5 minutes. If its visible and i think a pause of 0.026 is visible, people will say the game is unstable and badly coded.

If my data is correct and i didn’t made any mistake the problem isn’t from gc which is very stable but from the java2d api itself and the way it caches it’s resources.

#28

Is the rotation time-based or frame-based?

#29

There is a fixed angle increment per update. I have not changed this angle increment when i changed the target fps for the heavier tests so it gets a bit slower with lower fps values. But it could be easly made time based by using angular velocity instead of a fixed angle value.

#30

Heres the code:


package game2d.tests;

import game2d.imp.java2d.Java2DGameCanvas;
import game2d.imp.java2d.Java2DSpriteFactory;
import game2d.imp.java2d.Java2DSprite;
import game2d.util.FastLogger;
import game2d.util.Timer;

import java.awt.Graphics2D;
import java.awt.Color;
import java.awt.geom.AffineTransform;
import javax.swing.JFrame;


public class Java2DSpriteDrawTest2 {
	
	public static void main(String[] args) {
		new Java2DSpriteDrawTest2();
	}
	
	private Java2DSprite sprite;
	private JFrame frame;
	private Java2DGameCanvas canvas;
	private Java2DSpriteFactory factory;
	private int w;
	private int h;
	private int sw;
	private int sh;
	private Graphics2D gc;
	private FastLogger fastlog = new FastLogger();
	private Timer timer = Timer.getSingleton();
	private int[] spw;
	private int[] sph;
	private int numsp;
	private int numit;
	private double framedur;
	
	public Java2DSpriteDrawTest2() {
		canvas = new Java2DGameCanvas(800,600);
		w = canvas.getWidth();
		h = canvas.getHeight();
		frame = Java2DGameCanvas.createFrame("",canvas,null);
		factory = Java2DSpriteFactory.getSingleton();
		frame.pack();
		frame.setVisible(true);
		sprite = Java2DSpriteFactory.getSingleton().getSprite("sprites/pleg.png");
		sw = sprite.getWidth();
		sh = sprite.getHeight();
		start();
	}
	
	private void waitSeconds(double period) {
		double t0 = timer.getTime();
		double tm = t0;
		for (; tm - t0 < period; tm = timer.getTime()) ;
	}
	
	public void start() {
		numit = 200;
		numsp = 1000;
		framedur = 0.05;
		// init sprites
		spw = new int[numsp];
		sph = new int[numsp];
		for (int i=0; i < numsp; i++) {
			spw[i] = (int) (Math.random() * w);
			if (spw[i] < 128) spw[i] = 128;
			if (spw[i] > w - 128) spw[i] = w - 128;
			sph[i] = (int) (Math.random() * h);
			if (sph[i] < 128) sph[i] = 128;
			if (sph[i] > w - 128) sph[i] = w - 128;
		}
		// statistics
		double requestedFrame = framedur;
		double beforeUpdate;
		double updatePeriod = 0.0;
		double beforePresentation = 0.0;
		double presentationPeriod = 0.0;
		double beforeFilling = 0.0;
		double fillPeriod = 0.0;
		double latency = 0.0;
		double timeLeft = 0.0;
		double recoveryPeriod = 0.0;
		boolean skip = false;
		double beforeLogging;
		double loggingPeriod = 0.0;
		for (int i=0; i < numit; i++) {
			timeLeft = requestedFrame - recoveryPeriod;
			beforeUpdate = timer.getTime();
			update(); // allways update
			updatePeriod = timer.getTime() - beforeUpdate;
			timeLeft -= updatePeriod; 
			// only draw if there is possibly time for it
			beforePresentation = timer.getTime();
			if (timeLeft >= 0) {
				skip = false;
				draw();
			} else {
				// tell fastlog a frame was skiped
				skip = true;
			}
			presentationPeriod = timer.getTime() - beforePresentation;
			timeLeft -= presentationPeriod;
			// fill any remaining time if there is some
			// computer recovery period
			latency = 0.0;
			fillPeriod = 0.0;
			if (timeLeft >= 0) {
				beforeFilling = timer.getTime();
				waitSeconds(timeLeft);
				fillPeriod = timer.getTime() - beforeFilling;
				latency = fillPeriod - timeLeft;
				recoveryPeriod = latency;
			} else {
				// frame toke too much time to draw
				recoveryPeriod = -timeLeft;
			}
			beforeLogging = timer.getTime();
			fastlog.push(skip, updatePeriod, presentationPeriod, 
					fillPeriod, latency, recoveryPeriod);
			loggingPeriod = timer.getTime() - beforeLogging;
			recoveryPeriod += loggingPeriod;
		}
		fastlog.print(System.out);
	}
	
	private double rot = 0.0;
	
	public void update() {
		rot += Math.PI/48.0;
	}
	
	private AffineTransform identity = new AffineTransform(); 
	public void draw() {
		gc = canvas.getDrawGraphics();
		gc.setColor(Color.black);
		gc.fillRect(0,0,w,h);
		for (int i=0; i < numsp; i++) {
			gc.setTransform(identity);
			gc.translate(spw[i]-sw,sph[i]-sh);
			gc.rotate(rot,sw/2.0,sh/2.0);
			gc.drawImage(sprite.getImage(), 0, 0, null);
		}
		gc.dispose();
		canvas.flip();
	}
	
}
#31

One thing that occurred to me about time based movement, is that the timing is always one frame behind, which can cause noticable flaws in movement. Which is why I stick with tick based movement with a fixed frame rate in my current game with a frame skipping function to make up for any occasional hick-ups.

#32

I don’t understand exactly what you guys are saying when you mention time based and frame based animation. What is the difference exactly? In my code for example i just fix a target fps value and ensure that each rendering update wastes exactly the time alocated for each frame and if it wastes too much then i skip render updates until i get on track again.

However an easier method than my previous code would be simply to record tha animation start time on a variable and then compute the anim frame i need to use to render based on the formula ((current time - start time) % fps) if it is a looping animation. No frame behind issues this way.

#33

[quote]I don’t understand exactly what you guys are saying when you mention time based and frame based animation. What is the difference exactly?
[/quote]
With time based movement, the speed at which everything animates depends on how long the last frame took. This ensures that everything moves at the same speed, independently of the frame rate. Works great for 3D games, but sucks for 2D (especially scrolling games).

With tick based movement, the speed at which everything animates is fixed, so the speed of the movement depends on the framerate. If the frame rate drops, the game gets slower. So you need to ensure that your game logic updates at a constant rate, which may require the game to occasionally drop rendered frames if the target frame rate is not achieved.

If you throttle a time based game loop to a fixed, constant frame rate, it will basically behave the same as tick based movement (if the target frame rate is always achieved).

So what you’re doing is basically tick (or frame) based movement.

[quote]However an easier method than my previous code would be simply to record tha animation start time on a variable and then compute the anim frame i need to use to render based on the formula ((current time - start time) % fps) if it is a looping animation. No frame behind issues this way.
[/quote]
This looks more like time based animation, but it doesn’t take movement of your game objects in account.

Maybe I’m just doing it wrong or maybe there’s an error in my thinking, but when I implement time based movement, I have a method in all game objects like this:

public void update(float deltaTime) {... }

Where deltaTime is the time which the last frame took to complete, which is used to scale the movement. So the next frame’s animation might be off, if the current frame will take a drastically different amount of time to complete, because the current frame update is based on the time from the previous frame update, which was already displayed.

#34

“If you throttle a time based game loop to a fixed, constant frame rate, it will basically behave the same as tick based movement (if the target frame rate is always achieved).”

The problem here is the Thread.sleep method. No mater what method is used sleeping allways wastes more than it should because it’s very innacurate in java 1.5. Don’t know if it has changed in java 1.6 but the error is something between 1 millisecond and sometimes it can miss by much more. I used a brute force sleep method so i can simply ignore this.

“Maybe I’m just doing it wrong or maybe there’s an error in my thinking, but when I implement time based movement, I have a method in all game objects like this:
Code: public void update(float deltaTime) {… }”

Thats a common usage of the update method. However if you have a singleton object that manages time statistics for your game - lets call it Scheduller for example - you can obtain deltaTime from this object instead when you call the update method. For example:


// init
Scheduller sch = Scheduller.getSingleton();
// game loop
// inside update 
void update() {
    double delta = sch.getDelta(); 
     // do something 
}
// inside renderer 
void render() {
    double delta = sch.getDelta(); 
     // do something 
}
// finaly 
sch.tick();

It may be easier to collect statistics this way.

#35

Throttling is always a pain.
Since java 1.5, the throttling code in JEmu2 isn’t reliable anymore in some cases. Specifically one case where I want a frame rate of 50fps and a display refresh rate of 100Hz. I both sync to the display, and throttle to get 50fps, but since 1.5 the throttling somehow gets confused and it ends up running at 100fps. I’m quite sure the logic of the throttling is okay, but it seems as if currentTimeMillis can get confused with lots of 1ms sleeps in a tight loop, because if I print the numbers of how long it tries to sleep and how much it actually throttled, the numbers are okay (it reports 50fps, 20ms per frame), but the visible end result is wrong (100fps). Very weird. Also without sync to vblank (throttle only) this is the case.
And then there’s the issues with some configurations when you use a high precision timer, which is another reason I’m currently avoiding time based movement. With 1ms precision, it’s not accurate enough to ensure that the physics of the game are always consistent.

#36

You can test time just before buffer flip, and redraw as neccessary.

#37

System.currentTimeMillis() is too inaccurate to try to measure frame rate on windows (55ms accuracy). System.nanoTIme() is the way to go, then throttling should be OK.

The only problem I can see with time-based movement is what ErikD was getting at earlier, and that is that if the draw-time is not constant, then a longer than average frame-draw will be displayed which has a small update time applied to it that >> so that frame would be lagged. (If the GC were to come in during the frame draw then it would be lagged too)

All frames after that would be OK though since the long lag would be compensated for in the next frame which would have had a bigger update time applied to it. As long as the frame rate is quick, so a lagged frame doesn’t hang around for long, they eye shouldn’t notice this problem too much.

I see little advantage at all to tick-based movement, its really just time-based movement with a hard-coded time >> what’s the point?

#38

Determinism. Predictability. Stability.

#39

[quote]Determinism. Predictability. Stability.
[/quote]
To elaborate on that: I still wonder why so much people use frame-based updates. The more the framerate varies, the larger the error (think of a vehicle making a circle). It’s much harder to sync everybody in multiplayer games, and the update process becomes slightly more complicated, because you have to multiply everything by the elapsed time, or worse, when dealing with acceleration and rotation.

The alternative, tick-based updates is extremely stable, will give the same results whatever the framerate, and is easy to sync.

That is pretty much the point :slight_smile:

#40

[quote]Determinism. Predictability. Stability.
[/quote]
Exactly.
Nobody can guarantee if high resolution timers will work or will really be high resolution at all.
Especially if you do 2D scrollers, tick based movement with a fixed vsync’ed framerate is the way to go if you want the scrolling to be as fluid as it can be. Now you can’t guarantee VSync as well, but you don’t really need a high resolution timer to get a reasonably stable 60fps if VSync doesn’t work.
Even for my simple 3D game I stick to tick based, because it turned out that time based made the game unpredictable (sometimes you couldn’t make a jump which you could in other cases), and in that game it’s absolutely vital that it’s predictable. The underlying code is actually time based, but I feed it a fixed time every frame. That way I can scale the game speed to the display’s refresh frequency if 60Hz can not be chosen for any reason.