Added profiling support to WindowsOnscreenGLDrawable to figure out why

JOGL applets running in Mozilla/Firefox are so slow -- apparently the
WINGDI call SwapBuffers() is taking a long time, but unclear why


git-svn-id: file:///usr/local/projects/SUN/JOGL/git-svn/svn-server-sync/jogl/trunk@569 232f8b59-042b-4e1e-8c03-345bb8c30851

1 files changed, 56 insertions, 0 deletions

diff --git a/src/classes/com/sun/opengl/impl/windows/WindowsOnscreenGLDrawable.java b/src/classes/com/sun/opengl/impl/windows/WindowsOnscreenGLDrawable.java
index bc21c58b7..08902b573 100644
--- a/src/classes/com/sun/opengl/impl/windows/WindowsOnscreenGLDrawable.java
+++ b/src/classes/com/sun/opengl/impl/windows/WindowsOnscreenGLDrawable.java
@@ -68,6 +68,15 @@ public class WindowsOnscreenGLDrawable extends WindowsGLDrawable {
   // addNotify() is called on the component.
   protected boolean realized;
 
+  private static final boolean PROFILING = Debug.debug("WindowsOnscreenGLDrawable.profiling");
+  private static final int PROFILING_TICKS = 200;
+  private int  profilingLockSurfaceTicks;
+  private long profilingLockSurfaceTime;
+  private int  profilingUnlockSurfaceTicks;
+  private long profilingUnlockSurfaceTime;
+  private int  profilingSwapBuffersTicks;
+  private long profilingSwapBuffersTime;
+
   public WindowsOnscreenGLDrawable(Component component,
                                    GLCapabilities capabilities,
                                    GLCapabilitiesChooser chooser) {
@@ -109,10 +118,27 @@ public class WindowsOnscreenGLDrawable extends WindowsGLDrawable {
       didLock = true;
     }
 
+    long startTime = 0;
+    if (PROFILING) {
+      startTime = System.currentTimeMillis();
+    }
+
     if (!WGL.SwapBuffers(hdc) && (WGL.GetLastError() != 0)) {
       throw new GLException("Error swapping buffers");
     }
 
+    if (PROFILING) {
+      long endTime = System.currentTimeMillis();
+      profilingSwapBuffersTime += (endTime - startTime);
+      int ticks = PROFILING_TICKS;
+      if (++profilingSwapBuffersTicks == ticks) {
+        System.err.println("SwapBuffers calls: " + profilingSwapBuffersTime + " ms / " + ticks + "  calls (" +
+                           ((float) profilingSwapBuffersTime / (float) ticks) + " ms/call)");
+        profilingSwapBuffersTime = 0;
+        profilingSwapBuffersTicks = 0;
+      }
+    }
+
     if (didLock) {
       unlockSurface();
     }
@@ -125,6 +151,10 @@ public class WindowsOnscreenGLDrawable extends WindowsGLDrawable {
     if (hdc != 0) {
       throw new GLException("Surface already locked");
     }
+    long startTime = 0;
+    if (PROFILING) {
+      startTime = System.currentTimeMillis();
+    }
     ds = JAWT.getJAWT().GetDrawingSurface(component);
     if (ds == null) {
       // Widget not yet realized
@@ -166,6 +196,17 @@ public class WindowsOnscreenGLDrawable extends WindowsGLDrawable {
     if (!pixelFormatChosen) {
       choosePixelFormat(true);
     }
+    if (PROFILING) {
+      long endTime = System.currentTimeMillis();
+      profilingLockSurfaceTime += (endTime - startTime);
+      int ticks = PROFILING_TICKS;
+      if (++profilingLockSurfaceTicks == ticks) {
+        System.err.println("LockSurface calls: " + profilingLockSurfaceTime + " ms / " + ticks + " calls (" +
+                           ((float) profilingLockSurfaceTime / (float) ticks) + " ms/call)");
+        profilingLockSurfaceTime = 0;
+        profilingLockSurfaceTicks = 0;
+      }
+    }
     return ret;
   }
 
@@ -173,6 +214,10 @@ public class WindowsOnscreenGLDrawable extends WindowsGLDrawable {
     if (hdc == 0) {
       throw new GLException("Surface already unlocked");
     }
+    long startTime = 0;
+    if (PROFILING) {
+      startTime = System.currentTimeMillis();
+    }
     ds.FreeDrawingSurfaceInfo(dsi);
     ds.Unlock();
     JAWT.getJAWT().FreeDrawingSurface(ds);
@@ -180,5 +225,16 @@ public class WindowsOnscreenGLDrawable extends WindowsGLDrawable {
     dsi = null;
     win32dsi = null;
     hdc = 0;
+    if (PROFILING) {
+      long endTime = System.currentTimeMillis();
+      profilingUnlockSurfaceTime += (endTime - startTime);
+      int ticks = PROFILING_TICKS;
+      if (++profilingUnlockSurfaceTicks == ticks) {
+        System.err.println("UnlockSurface calls: " + profilingUnlockSurfaceTime + " ms / " + ticks + " calls (" +
+                           ((float) profilingUnlockSurfaceTime / (float) ticks) + " ms/call)");
+        profilingUnlockSurfaceTime = 0;
+        profilingUnlockSurfaceTicks = 0;
+      }
+    }
   }
 }