I was under the impression that I could tell how long it’d take to render something by wrapping an appropriate subsection of the display(GLDrawable) function with time-checks and noting the elapsed time:
Ex.
before = hires.getTime()
gl.glBegin( GL.GL_QUADS )…gl.glEnd()
elapsed = hires.getTime()-before
While this method seems to capture some of the time required to perform a particular render, I’ve recently noticed another associated time that is, in some cases, many times more important (say 400x for large shapes) and requires more careful benchmarking. The time I refer to is the delay between successive display(GLDrawable) calls by an Animator which, as far as I can tell, is calling display in a pretty tight loop.
For example, when drawing 200 620x460 white quads to the screen on my p4/radeon.mobility.9000, the ‘direct’, timer-wrapped elapsed time is about 00.14ms, while the time between successive display calls jumps to around 63.52ms. I’m sure that the successive call delay is directly related to the quad rendering because cutting the number-to-render in half also halves the successive display wait, and forgoing renders altogether brings successive display wait to a (healthy?) baseline of about 1.8ms.
I’m sure I must misunderstand something fundamental about how the OGL framebuffer gets swapped onscreen, or else this latency is the result of some enormous performance-destroying bug.
Please straighten me out 
Example program to illustrate what I’m talking about:
/* Demonstrates the (strange?) pauses between display(GLDrawable) calls
* managed by an Animator when large amounts of area are filled during each
* display call. On my p4/mobility radeon 9000, high-res timing indicates
* that the time _between_ display() calls is over 400x the time spent
* within a particular display() function call when several hundred large
* white quads are drawn to the screen each display() (63.52ms vs 00.14ms).
********************************************************************************/
import java.awt.*;
import java.awt.event.*;
import sun.misc.Perf;
import net.java.games.jogl.*;
public final class DDelay extends Frame implements GLEventListener, KeyListener
{
private GraphicsDevice gd;
private DisplayMode dm;
// JOGL:
private GLCanvas canvas;
private Animator animator;
public static void main( String[] args )
{
boolean openFullScreen = args.length >= 1 && args[0].equals("y");
System.out.println( "open fullscreen = "+openFullScreen );
DDelay test = new DDelay( openFullScreen );
test.show();
}
public DDelay( boolean fs )
{
super( "Strange Delay Between display(GLDrawable) Calls" );
GLCanvas canvas = GLDrawableFactory.getFactory().createGLCanvas( new GLCapabilities() );
canvas.addGLEventListener( this );
add( canvas );
animator = new Animator( canvas );
addKeyListener( this );
addWindowListener( new WindowAdapter(){public void windowClosing( WindowEvent e ){close();System.exit( 0 );}});
gd = getGraphicsConfiguration().getDevice();
dm = new DisplayMode( 640, 480, gd.getDisplayMode().getBitDepth(), gd.getDisplayMode().getRefreshRate() );
fs = fs && ( dm != null && gd.isFullScreenSupported() );
setIgnoreRepaint( true );
setResizable( false );
setUndecorated( fs );
if( fs )
{
gd.setFullScreenWindow( this );
gd.setDisplayMode( dm );
}
else
{
pack();
Insets insets = getInsets();
int w = 640+insets.left+insets.right;
int h = 480+insets.top+insets.bottom;
setSize( w, h );
Dimension screenSize = Toolkit.getDefaultToolkit().getScreenSize();
setLocation( (screenSize.width-w)/2, (screenSize.height-h)/2 );
show();
}
animator.start();
}
// GLEventListener:
public void init( GLDrawable drawable )
{
GL gl = drawable.getGL();
gl.glEnable( GL.GL_DEPTH_TEST );
gl.glEnable( GL.GL_CULL_FACE );
drawable.addKeyListener( this );
}
public void reshape( GLDrawable drawable, int x, int y, int width, int height )
{
GL gl = drawable.getGL();
GLU glu = drawable.getGLU();
gl.glViewport( 0, 0, width, height );
gl.glMatrixMode( GL.GL_PROJECTION );
gl.glLoadIdentity();
// java-style display coordinates, (0,0) is top left
glu.gluOrtho2D( 0, 640, 480, 0 );
gl.glMatrixMode( GL.GL_MODELVIEW );
}
public void displayChanged( GLDrawable arg0, boolean arg1, boolean arg2 ) {}
public void display( GLDrawable drawable )
{
// begin display, record time for future printing
double startDisplay = Timer.getTime();
double betweenDisplays = startDisplay - endDisplay;
GL gl = drawable.getGL();
gl.glClear( GL.GL_COLOR_BUFFER_BIT | GL.GL_DEPTH_BUFFER_BIT | GL.GL_ACCUM_BUFFER_BIT );
gl.glColor3f( 1.0f, 1.0f, 1.0f );
// draw a simple quad occupying most of the screen, 200 times (one on top of the next)
for( int i = 0; i < 200; i++ )
{
gl.glBegin( GL.GL_QUADS );
gl.glVertex2i( 10, 470 );
gl.glVertex2i( 630, 470 );
gl.glVertex2i( 630, 10 );
gl.glVertex2i( 10, 10 );
gl.glEnd();
}
// Every second, print how much time was spent drawing the quads, and how much time was spent between display() calls:
if( lastPrint == 0 )
lastPrint = Timer.getTime();
else if( startDisplay - lastPrint > PRINT_DELAY )
{
System.out.println( "Between display()'s for "+printFormat.format(betweenDisplays) + " milliseconds" );
System.out.println( "Rendering display() for "+printFormat.format(lastRenderTime) + " milliseconds" );
System.out.println( "--------------------------------------------" );
lastPrint = startDisplay;
}
// end display, record time for future printing
endDisplay = Timer.getTime();
lastRenderTime = endDisplay - startDisplay;
}
private final static java.text.NumberFormat printFormat = java.text.NumberFormat.getNumberInstance();
static
{
printFormat.setMinimumIntegerDigits(3);printFormat.setMinimumIntegerDigits(3);printFormat.setMinimumFractionDigits(3);printFormat.setMaximumFractionDigits(3);
}
private final static double PRINT_DELAY = 1000;
private double lastPrint;
private double lastRenderTime;
private double endDisplay;
// KeyListener:
public final void keyTyped( KeyEvent e ){}
public final void keyPressed( KeyEvent e )
{
if( e.getKeyCode() == KeyEvent.VK_ESCAPE )
{
close();
System.exit( 0 );
}
}
public final void keyReleased( KeyEvent e ){}
public final void close(){ animator.stop(); }
}
final class Timer
{
static Perf hiResTimer;
static double freq;
static
{
hiResTimer = Perf.getPerf();
freq = hiResTimer.highResFrequency();
}
public static double getTime()
{
return hiResTimer.highResCounter() * 1000.0 / freq;
}
}
And some example output:
Between display()'s for 127.347 milliseconds
Rendering display() for 000.142 milliseconds
Between display()'s for 063.521 milliseconds
Rendering display() for 000.115 milliseconds
Oh yeah, every once in a while the generally consistent between-display time will spike by a factor of ~2. And enabling DEPTH_TEST seemed to reduce between-display delay by about 40%.
Also, any advice on how to measure actual, total render time an operation ends up consuming, short of isolating the operation in its own test program and measuring successive display wait, would be nice. Online OGL FAQs of apparent repute seem to indicate the sort of direct benchmarking I’ve tried would work…